-- Logs begin at Thu 2019-02-14 15:41:58 IST, end at Mon 2025-06-30 18:51:29 IST. -- Jun 30 18:50:00 volumio wireless.js[612]: trying... Jun 30 18:50:00 volumio sudo[970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 30 18:50:00 volumio sudo[970]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:00 volumio sudo[970]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:01 volumio wireless.js[612]: trying... Jun 30 18:50:01 volumio sudo[973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 30 18:50:01 volumio sudo[973]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:01 volumio sudo[973]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:02 volumio wireless.js[612]: trying... Jun 30 18:50:02 volumio sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 30 18:50:02 volumio sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:02 volumio sudo[976]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:02 volumio dhcpcd[918]: wlan0: leased 192.168.1.15 for 86400 seconds Jun 30 18:50:02 volumio avahi-daemon[603]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.15. Jun 30 18:50:02 volumio avahi-daemon[603]: New relevant interface wlan0.IPv4 for mDNS. Jun 30 18:50:02 volumio avahi-daemon[603]: Registering new address record for 192.168.1.15 on wlan0.IPv4. Jun 30 18:50:02 volumio dhcpcd[918]: wlan0: adding route to 192.168.1.0/24 Jun 30 18:50:02 volumio dhcpcd[918]: wlan0: adding default route via 192.168.1.1 Jun 30 18:50:03 volumio wireless.js[612]: trying... Jun 30 18:50:03 volumio sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 30 18:50:03 volumio sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:03 volumio sudo[999]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:03 volumio wireless.js[612]: Connected to: ----dlink Jun 30 18:50:03 volumio wireless.js[612]: ---- Jun 30 18:50:03 volumio sudo[1002]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 30 18:50:03 volumio sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:03 volumio sudo[1002]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:03 volumio wireless.js[612]: ... joined AP, wlan0 IPv4 is 192.168.1.15, ipV6 is undefined Jun 30 18:50:03 volumio wireless.js[612]: It's done! AP Jun 30 18:50:03 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 30 18:50:03 volumio systemd[1]: Started Wireless Services. Jun 30 18:50:03 volumio systemd[1]: Started Volumio Backend Module. Jun 30 18:50:03 volumio systemd[1]: Started Volumio Cpu Tweaker. Jun 30 18:50:03 volumio volumio-cpu-tweak[1008]: Setting RT Priority for mpd Jun 30 18:50:03 volumio volumio-cpu-tweak[1008]: Setting MPD Affinity Jun 30 18:50:03 volumio volumio-cpu-tweak[1008]: pid 819's current affinity mask: f Jun 30 18:50:03 volumio volumio-cpu-tweak[1008]: pid 819's new affinity mask: 3 Jun 30 18:50:03 volumio volumio-cpu-tweak[1008]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 30 18:50:03 volumio volumio-cpu-tweak[1008]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jun 30 18:50:03 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 30 18:50:04 volumio ntpd[805]: Listen normally on 3 wlan0 192.168.1.15:123 Jun 30 18:50:04 volumio ntpd[805]: new interface(s) found: waking up resolver Jun 30 18:50:04 volumio volumio-time-update[629]: volumio-time-update-util: Fetching time from Volumio... Jun 30 18:50:05 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:05 volumio volumio[1007]: info: ----- Volumio3 ---- Jun 30 18:50:05 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:05 volumio volumio[1007]: info: ----- System startup ---- Jun 30 18:50:05 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:05 volumio volumio-time-update[629]: volumio-time-update-util: Setting system time to: 2025-06-30 18:50:33 Jun 30 18:50:05 volumio sudo[1037]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-06-30 18:50:33 Jun 30 18:50:05 volumio sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:05 volumio dbus-daemon[620]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=1038 comm="timedatectl set-time 2025-06-30 18:50:33 ") Jun 30 18:50:05 volumio systemd[1]: Starting Time & Date Service... Jun 30 18:50:05 volumio dbus-daemon[620]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 30 18:50:05 volumio systemd[1]: Started Time & Date Service. Jun 30 18:50:33 volumio systemd-timedated[1039]: Changed local time to Mon Jun 30 18:50:33 2025 Jun 30 18:50:33 volumio sudo[1037]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:33 volumio volumio-time-update[629]: volumio-time-update-util: System time updated successfully. Jun 30 18:50:33 volumio systemd[1]: Started Volumio Time Update Utility. Jun 30 18:50:33 volumio volumio[1007]: info: MYVOLUMIO Environment detected Jun 30 18:50:33 volumio volumio[1007]: info: Plugin folders cleanup Jun 30 18:50:33 volumio volumio[1007]: info: Scanning into folder /volumio/app/plugins/ Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category audio_interface Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category miscellanea Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category music_service Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category plugins.json Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category system_controller Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category user_interface Jun 30 18:50:33 volumio volumio[1007]: info: Scanning into folder /data/plugins/ Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category audio_interface Jun 30 18:50:33 volumio volumio[1007]: info: Scanning category music_service Jun 30 18:50:33 volumio volumio[1007]: info: Plugin folders cleanup completed Jun 30 18:50:33 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:33 volumio volumio[1007]: info: ----- Core plugins startup ---- Jun 30 18:50:33 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:33 volumio volumio[1007]: info: Loading plugins from folder /volumio/app/plugins/ Jun 30 18:50:33 volumio volumio[1007]: info: Adding plugin upnp to MyMusic Plugins Jun 30 18:50:33 volumio volumio[1007]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 30 18:50:33 volumio volumio[1007]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 30 18:50:33 volumio volumio[1007]: info: Loading plugins from folder /data/plugins/ Jun 30 18:50:33 volumio volumio[1007]: info: Loading plugin "system"... Jun 30 18:50:33 volumio volumio[1007]: info: Loading plugin "appearance"... Jun 30 18:50:33 volumio nmbd[778]: [2025/06/30 18:50:33.683624, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 30 18:50:33 volumio systemd[1]: Started Samba NMB Daemon. Jun 30 18:50:33 volumio nmbd[778]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 30 18:50:33 volumio systemd[1]: Starting Samba Winbind Daemon... Jun 30 18:50:33 volumio winbindd[1045]: [2025/06/30 18:50:33.982007, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 30 18:50:33 volumio winbindd[1045]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 30 18:50:34 volumio winbindd[1045]: [2025/06/30 18:50:34.009359, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 30 18:50:34 volumio systemd[1]: Started Samba Winbind Daemon. Jun 30 18:50:34 volumio winbindd[1045]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 30 18:50:34 volumio systemd[1]: Starting Samba SMB Daemon... Jun 30 18:50:34 volumio winbindd[1045]: [2025/06/30 18:50:34.406508, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Jun 30 18:50:34 volumio winbindd[1045]: res_names->count = 3, expected 4 Jun 30 18:50:34 volumio smbd[1050]: [2025/06/30 18:50:34.431516, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 30 18:50:34 volumio systemd[1]: Started Samba SMB Daemon. Jun 30 18:50:34 volumio systemd[1]: Reached target Multi-User System. Jun 30 18:50:34 volumio systemd[1]: Reached target Graphical Interface. Jun 30 18:50:34 volumio smbd[1050]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 30 18:50:34 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 30 18:50:34 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 30 18:50:34 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 30 18:50:34 volumio systemd[1]: Startup finished in 12.104s (kernel) + 25.738s (userspace) = 37.842s. Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "network"... Jun 30 18:50:34 volumio volumio[1007]: info: Refreshing Cached IP Addresses Jun 30 18:50:34 volumio sudo[1060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 30 18:50:34 volumio sudo[1060]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:34 volumio sudo[1060]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:34 volumio sudo[1062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 30 18:50:34 volumio sudo[1062]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:34 volumio sudo[1062]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "services"... Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "alsa_controller"... Jun 30 18:50:34 volumio sudo[1071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 30 18:50:34 volumio sudo[1071]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:34 volumio volumio-remote-updater[604]: [2025-06-30 18:50:34] [connect] Successful connection Jun 30 18:50:34 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "wizard"... Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "networkfs"... Jun 30 18:50:34 volumio volumio[1007]: info: Starting Udev Watcher for removable devices Jun 30 18:50:34 volumio volumio[1007]: info: Ignoring mount for partition: boot Jun 30 18:50:34 volumio volumio[1007]: info: Ignoring mount for partition: volumio Jun 30 18:50:34 volumio volumio[1007]: info: Ignoring mount for partition: volumio_data Jun 30 18:50:34 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "volumio_command_line_client"... Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "upnp"... Jun 30 18:50:34 volumio volumio[1007]: info: [1751289634792] Starting Upmpd Daemon Jun 30 18:50:34 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "my_music"... Jun 30 18:50:34 volumio volumio[1007]: info: Loading plugin "mpd"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "upnp_browser"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "alarm-clock"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "airplay_emulation"... Jun 30 18:50:35 volumio volumio[1007]: info: Starting Shairport Sync Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "last_100"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "webradio"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "i2s_dacs"... Jun 30 18:50:35 volumio volumio[1007]: info: I2S DAC not set, start Auto-detection Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "volumiodiscovery"... Jun 30 18:50:35 volumio volumio[1007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 30 18:50:35 volumio volumio[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 30 18:50:35 volumio node[1007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 30 18:50:35 volumio volumio[1007]: *** WARNING *** For more information see Jun 30 18:50:35 volumio volumio[1007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 30 18:50:35 volumio volumio[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 30 18:50:35 volumio volumio[1007]: *** WARNING *** For more information see Jun 30 18:50:35 volumio node[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 30 18:50:35 volumio node[1007]: *** WARNING *** For more information see Jun 30 18:50:35 volumio node[1007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 30 18:50:35 volumio node[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 30 18:50:35 volumio node[1007]: *** WARNING *** For more information see Jun 30 18:50:35 volumio volumio[1007]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 30 18:50:35 volumio volumio[1007]: info: Discovery: Started advertising with name: Volumio Jun 30 18:50:35 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 30 18:50:35 volumio volumio[1007]: info: Plugin squeezelite_mc is not enabled Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "outputs"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "albumart"... Jun 30 18:50:35 volumio volumio[1007]: info: Plugin example_plugin is not enabled Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "inputs"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "updater_comm"... Jun 30 18:50:35 volumio volumio[1007]: info: Plugin mpdemulation is not enabled Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "rest_api"... Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "websocket"... Jun 30 18:50:35 volumio volumio[1007]: info: Starting Socket.io Server version 2.3.0 Jun 30 18:50:35 volumio volumio[1007]: info: Loading plugin "fusiondsp"... Jun 30 18:50:35 volumio volumio[1007]: Forking 3 albumart workers Jun 30 18:50:36 volumio volumio[1007]: info: Applying required configuration parameters for plugin fusiondsp Jun 30 18:50:36 volumio volumio[1007]: info: Loading plugin "RoonBridge"... Jun 30 18:50:36 volumio volumio[1007]: Starting albumart workers Jun 30 18:50:36 volumio volumio[1007]: Starting albumart workers Jun 30 18:50:36 volumio volumio[1007]: Starting albumart workers Jun 30 18:50:36 volumio volumio[1007]: info: Applying required configuration parameters for plugin RoonBridge Jun 30 18:50:36 volumio volumio[1007]: info: Loading plugin "lms"... Jun 30 18:50:37 volumio volumio[1007]: info: Loading plugin "radio_paradise"... Jun 30 18:50:37 volumio volumio[1007]: info: Applying required configuration parameters for plugin radio_paradise Jun 30 18:50:37 volumio volumio[1007]: info: [1751289637213] [RadioParadise] API delay: 5 Jun 30 18:50:37 volumio volumio[1007]: info: Loading i18n strings for locale en Jun 30 18:50:37 volumio volumio[1007]: Updating browse sources language Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::initPlayerControls Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: Express server listening on port 3000 Jun 30 18:50:37 volumio volumio[1007]: [Metrics] WebUI: 5s 321.79ms Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::resetVolumioState Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::getcurrentVolume Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioRetrievevolume Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: Volumio Network Manager: Network status updated: 2 Jun 30 18:50:37 volumio volumio-remote-updater[604]: [2025-06-30 18:50:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1751289634 101 Jun 30 18:50:37 volumio volumio[1007]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Jun 30 18:50:37 volumio volumio[1007]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.8 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 2 Jun 30 18:50:37 volumio volumio[1007]: info: Reloading queue from file Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::setRepeat false single undefined Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:37 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::setRandom null Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:37 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:37 volumio volumio[1007]: info: Setting Device type: Raspberry PI Jun 30 18:50:37 volumio volumio[1007]: info: VolumeController:: Volume=100 Mute =false Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:37 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:37 volumio volumio[1007]: info: CoreStateMachine::updateTrackBlock Jun 30 18:50:37 volumio volumio[1007]: info: CorePlayQueue::getTrackBlock Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioRetrievevolume Jun 30 18:50:37 volumio volumio[1007]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 30 18:50:37 volumio volumio[1007]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03115 Jun 30 18:50:37 volumio volumio[1007]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 30 18:50:37 volumio volumio[1007]: info: Completed loading Core Plugins Jun 30 18:50:37 volumio volumio[1007]: info: Preparing to generate the ALSA configuration file Jun 30 18:50:37 volumio volumio[1007]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 30 18:50:37 volumio volumio[1007]: info: Reading ALSA contributions from plugins. Jun 30 18:50:37 volumio volumio[1007]: info: Asound.conf file unchanged, so no further update is needed Jun 30 18:50:37 volumio volumio[1007]: info: Output device has changed, restarting MPD Jun 30 18:50:37 volumio sudo[1157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 30 18:50:37 volumio volumio[1007]: info: Output device has changed, restarting Shairport Sync Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:37 volumio sudo[1157]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio sudo[1157]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:37 volumio sudo[1159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 30 18:50:37 volumio sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio systemd[1]: Stopping Music Player Daemon... Jun 30 18:50:37 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 30 18:50:37 volumio volumio[1007]: info: ___________ START PLUGINS ___________ Jun 30 18:50:37 volumio volumio[1007]: info: ControllerMpd::onStart: Initializing MPD Jun 30 18:50:37 volumio volumio[1007]: info: Creating MPD Configuration file Jun 30 18:50:37 volumio sudo[1166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 30 18:50:37 volumio volumio[1007]: info: [1751289637766] CoreMusicLibrary::Adding element Media Servers Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:37 volumio sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio sudo[1166]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:37 volumio sudo[1168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 30 18:50:37 volumio sudo[1168]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:37 volumio systemd[1]: mpd.service: Succeeded. Jun 30 18:50:37 volumio systemd[1]: Stopped Music Player Daemon. Jun 30 18:50:37 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 30 18:50:37 volumio volumio[1007]: info: [1751289637859] CoreMusicLibrary::Adding element Last_100 Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 30 18:50:37 volumio volumio[1007]: info: [1751289637861] CoreMusicLibrary::Adding element Webradio Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 30 18:50:37 volumio volumio[1007]: info: Initializing BBC Radios Jun 30 18:50:37 volumio systemd[1]: Starting Music Player Daemon... Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: Loading i18n strings for locale en Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:37 volumio volumio[1007]: info: FusionDsp - mixtype--------------------- Hardware Jun 30 18:50:37 volumio sudo[1189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jun 30 18:50:37 volumio sudo[1189]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 30 18:50:37 volumio sudo[1176]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 30 18:50:37 volumio volumio[1007]: info: [1751289637962] CoreMusicLibrary::Adding element Radio Paradise Jun 30 18:50:37 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:37 volumio sudo[1176]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio volumio[1007]: Cannot find translation for source Radio Paradise Jun 30 18:50:37 volumio volumio[1007]: info: Volumio Calling Home Jun 30 18:50:37 volumio sudo[1191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Jun 30 18:50:37 volumio sudo[1191]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:37 volumio sudo[1176]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:37 volumio systemd[1]: Started RoonBridge. Jun 30 18:50:38 volumio sudo[1189]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Jun 30 18:50:38 volumio systemd[1]: Starting Logitech Media Server Daemon... Jun 30 18:50:38 volumio systemd[1]: Started Logitech Media Server Daemon. Jun 30 18:50:38 volumio sudo[1191]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio systemd[1209]: logitechmediaserver.service: Failed to execute command: No such file or directory Jun 30 18:50:38 volumio volumio[1007]: info: Preparing to generate the ALSA configuration file Jun 30 18:50:38 volumio systemd[1209]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory Jun 30 18:50:38 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC Jun 30 18:50:38 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. Jun 30 18:50:38 volumio volumio[1007]: info: Discovery: adding 9535a66e-9038-4f90-81ac-7107d677ce2c Jun 30 18:50:38 volumio volumio[1007]: info: Discovery: Found device Volumio Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:38 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:38 volumio volumio[1007]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 30 18:50:38 volumio volumio[1007]: info: Reading ALSA contributions from plugins. Jun 30 18:50:38 volumio volumio[1007]: info: logitechmediaserver started Jun 30 18:50:38 volumio volumio[1007]: info: MPD Permissions set Jun 30 18:50:38 volumio volumio[1007]: info: MPD Permissions set Jun 30 18:50:38 volumio volumio[1007]: info: VolumeController:: Volume=100 Mute =false Jun 30 18:50:38 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:38 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:38 volumio volumio[1007]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: Starting Shairport Sync Jun 30 18:50:38 volumio volumio[1007]: info: Starting Shairport Sync Jun 30 18:50:38 volumio sudo[1220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 30 18:50:38 volumio sudo[1220]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:38 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:38 volumio volumio[1007]: info: Starting Shairport Sync Jun 30 18:50:38 volumio sudo[1222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 30 18:50:38 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 30 18:50:38 volumio volumio[1007]: info: Asound.conf file unchanged, so no further update is needed Jun 30 18:50:38 volumio volumio[1007]: info: Output device has changed, restarting MPD Jun 30 18:50:38 volumio sudo[1222]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio sudo[1071]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio sudo[1225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 30 18:50:38 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 30 18:50:38 volumio sudo[1225]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 30 18:50:38 volumio volumio[1007]: info: Output device has changed, restarting Shairport Sync Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:38 volumio sudo[1231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 30 18:50:38 volumio sudo[1231]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 30 18:50:38 volumio sudo[1231]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio sudo[1232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 30 18:50:38 volumio sudo[1232]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 30 18:50:38 volumio sudo[1220]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio volumio[1007]: info: MPD Permissions set Jun 30 18:50:38 volumio volumio[1007]: info: Shairport-Sync Started Jun 30 18:50:38 volumio volumio[1007]: Error adding Membership: Error: addMembership EINVAL Jun 30 18:50:38 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 30 18:50:38 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 30 18:50:38 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 30 18:50:38 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 30 18:50:38 volumio sudo[1222]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio sudo[1225]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 30 18:50:38 volumio systemd[1]: mpd.service: Succeeded. Jun 30 18:50:38 volumio systemd[1]: Stopped Music Player Daemon. Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio systemd[1]: Starting Music Player Daemon... Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:38 volumio volumio[1007]: info: Shairport-Sync Started Jun 30 18:50:38 volumio volumio[1007]: info: Shairport-Sync Started Jun 30 18:50:38 volumio volumio[1007]: info: Starting Shairport Sync Jun 30 18:50:38 volumio sudo[1250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 30 18:50:38 volumio sudo[1250]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio sudo[1242]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 30 18:50:38 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 30 18:50:38 volumio sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:38 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 30 18:50:38 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 30 18:50:38 volumio sudo[1242]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 30 18:50:38 volumio sudo[1250]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:38 volumio volumio[1007]: info: Shairport-Sync Started Jun 30 18:50:38 volumio volumio[1007]: info: Volumio called home Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.007 Warn: get lock file path: /tmp/.rnbgem0- Jun 30 18:50:39 volumio mpd[1254]: Jun 30 18:50 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 30 18:50:39 volumio systemd[1]: Started Music Player Daemon. Jun 30 18:50:39 volumio sudo[1232]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:39 volumio sudo[1168]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:39 volumio sudo[1159]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:39 volumio volumio[1007]: info: Completed starting Core Plugins Jun 30 18:50:39 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:39 volumio volumio[1007]: info: ----- MyVolumio plugins startup ---- Jun 30 18:50:39 volumio volumio[1007]: info: ------------------------------------------- Jun 30 18:50:39 volumio volumio[1007]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 30 18:50:39 volumio volumio[1007]: error: MPD error: The expression evaluated to a falsy value: Jun 30 18:50:39 volumio volumio[1007]: assert.ok(self.idling) Jun 30 18:50:39 volumio volumio[1007]: error: The expression evaluated to a falsy value: Jun 30 18:50:39 volumio volumio[1007]: assert.ok(self.idling) Jun 30 18:50:39 volumio volumio[1007]: error: MPD error: The expression evaluated to a falsy value: Jun 30 18:50:39 volumio volumio[1007]: assert.ok(self.idling) Jun 30 18:50:39 volumio volumio[1007]: error: The expression evaluated to a falsy value: Jun 30 18:50:39 volumio volumio[1007]: assert.ok(self.idling) Jun 30 18:50:39 volumio volumio[1007]: info: MPD running with PID1254 Jun 30 18:50:39 volumio volumio[1007]: ,establishing connection Jun 30 18:50:39 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:50:39 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.355 Trace: [childprocess] using unix child process Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.407 Debug: PathForResource, filename: ../.update Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.467 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.472 Debug: PathForResource, filename: RAATServer Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.472 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.473 Debug: PathForResource, filename: RoonBridgeHelper Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.473 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Jun 30 18:50:39 volumio RoonBridge[1198]: Initializing Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.503 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Jun 30 18:50:39 volumio RoonBridge[1198]: 00:00:00.528 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Jun 30 18:50:39 volumio RoonBridge[1198]: Not Running (.o) Jun 30 18:50:39 volumio RoonBridge[1198]: Running Jun 30 18:50:39 volumio volumio[1007]: info: camilladsp service started and running in background, instance 1 Jun 30 18:50:39 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:50:40 volumio volumio[1007]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA Jun 30 18:50:40 volumio volumio[1007]: info: FusionDsp loaded Jun 30 18:50:40 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 30 18:50:40 volumio sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jun 30 18:50:40 volumio sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:40 volumio volumio[1007]: info: FusionDsp - Reporting Fusion DSP Enabled Jun 30 18:50:40 volumio volumio[1007]: info: Adding Signal Path Element [object Object] Jun 30 18:50:40 volumio volumio[1007]: info: Adding fusiondspeq DSP Signal Path Element Jun 30 18:50:40 volumio volumio[1007]: info: FusionDsp - ---- installed callbackRead Jun 30 18:50:40 volumio volumio[1007]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 30 18:50:40 volumio volumio[1007]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 30 18:50:40 volumio volumio[1007]: error: FusionDsp - WebSocket error: [object Object] Jun 30 18:50:40 volumio systemd[1]: Started FusionDsp Daemon. Jun 30 18:50:40 volumio sudo[1293]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:40 volumio RoonBridge[1198]: 00:00:00.020 Warn: get lock file path: /tmp/.rnbhgem0- Jun 30 18:50:41 volumio volumio[1007]: 0+0 records in Jun 30 18:50:41 volumio volumio[1007]: 0+0 records out Jun 30 18:50:41 volumio volumio[1007]: 0 bytes copied, 0.000137758 s, 0.0 kB/s Jun 30 18:50:41 volumio systemd[1]: systemd-fsckd.service: Succeeded. Jun 30 18:50:42 volumio volumio[1007]: 0+0 records in Jun 30 18:50:42 volumio volumio[1007]: 0+0 records out Jun 30 18:50:42 volumio volumio[1007]: 0 bytes copied, 0.000123795 s, 0.0 kB/s Jun 30 18:50:42 volumio sh[541]: timed out Jun 30 18:50:42 volumio dhcpcd[587]: timed out Jun 30 18:50:42 volumio sh[541]: dhcpcd exited Jun 30 18:50:42 volumio dhcpcd[587]: dhcpcd exited Jun 30 18:50:42 volumio sh[541]: ifup: failed to bring up eth0 Jun 30 18:50:42 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 30 18:50:42 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 30 18:50:42 volumio volumio[1007]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.8 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetVisibleSources Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 30 18:50:42 volumio volumio[1007]: info: Received Get System Info Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 30 18:50:42 volumio volumio[1007]: info: Discovery: Getting this device information Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: Listing playlists Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 30 18:50:42 volumio volumio[1007]: info: Received Get System Info Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 30 18:50:42 volumio volumio[1007]: info: Discovery: Getting this device information Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 30 18:50:42 volumio volumio[1007]: info: Received Get System Info Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 30 18:50:42 volumio volumio[1007]: info: Discovery: Getting this device information Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 30 18:50:42 volumio volumio[1007]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 30 18:50:42 volumio volumio[1007]: info: Received Get System Version Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 30 18:50:42 volumio volumio[1007]: info: Received Get System Info Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 30 18:50:42 volumio volumio[1007]: info: Discovery: Getting this device information Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetVisibleSources Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 30 18:50:42 volumio volumio[1007]: info: Received Get System Info Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 30 18:50:42 volumio volumio[1007]: info: Discovery: Getting this device information Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:50:42 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:42 volumio volumio[1007]: info: Listing playlists Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:50:42 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:50:42 volumio volumio[1007]: info: FusionDsp - IP adress is ---------------------------192.168.1.15 Jun 30 18:50:42 volumio volumio[1007]: info: FusionDsp - Jun 30 18:50:42 volumio volumio[1007]: info: FusionDsp - IP adress is ---------------------------192.168.1.15 Jun 30 18:50:42 volumio volumio[1007]: info: FusionDsp - Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - IP adress is ---------------------------192.168.1.15 Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - IP adress is ---------------------------192.168.1.15 Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - undefined Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - undefined Jun 30 18:50:43 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Jun 30 18:50:43 volumio volumio[1007]: 0+0 records in Jun 30 18:50:43 volumio volumio[1007]: 0+0 records out Jun 30 18:50:43 volumio volumio[1007]: 0 bytes copied, 0.000140462 s, 0.0 kB/s Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - undefined Jun 30 18:50:43 volumio volumio[1007]: info: FusionDsp - undefined Jun 30 18:50:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 30 18:50:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 30 18:50:44 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 30 18:50:44 volumio volumio[1007]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 30 18:50:44 volumio volumio[1007]: 0+0 records in Jun 30 18:50:44 volumio volumio[1007]: 0+0 records out Jun 30 18:50:44 volumio volumio[1007]: 0 bytes copied, 0.000115276 s, 0.0 kB/s Jun 30 18:50:44 volumio sudo[1369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 30 18:50:44 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:44 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:44 volumio sudo[1371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 30 18:50:44 volumio sudo[1371]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:44 volumio sudo[1371]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:44 volumio sudo[1375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 30 18:50:44 volumio sudo[1375]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:44 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Jun 30 18:50:44 volumio sudo[1375]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:44 volumio volumio[1007]: info: Upmpdcli Daemon Started Jun 30 18:50:45 volumio volumio[1377]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 30 18:50:45 volumio volumio[1007]: 0+0 records in Jun 30 18:50:45 volumio volumio[1007]: 0+0 records out Jun 30 18:50:45 volumio volumio[1007]: 0 bytes copied, 9.7295e-05 s, 0.0 kB/s Jun 30 18:50:46 volumio volumio[1007]: info: CoreCommandRouter::volumioGetQueue Jun 30 18:50:46 volumio volumio[1007]: info: CoreStateMachine::getQueue Jun 30 18:50:46 volumio volumio[1007]: info: CorePlayQueue::getQueue Jun 30 18:50:46 volumio volumio[1007]: 0+0 records in Jun 30 18:50:46 volumio volumio[1007]: 0+0 records out Jun 30 18:50:46 volumio volumio[1007]: 0 bytes copied, 9.7165e-05 s, 0.0 kB/s Jun 30 18:50:47 volumio volumio[1007]: 0+0 records in Jun 30 18:50:47 volumio volumio[1007]: 0+0 records out Jun 30 18:50:47 volumio volumio[1007]: 0 bytes copied, 0.000119406 s, 0.0 kB/s Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin bluetooth to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin multiroom to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin metavolumio to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin cd_controller to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin qobuzconnect to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 30 18:50:48 volumio volumio[1007]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 30 18:50:48 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:48 volumio volumio[1007]: info: Starting MyVolumio Remote Streaming Endpoints Jun 30 18:50:48 volumio volumio[1007]: info: MyVolumio login type: Token Jun 30 18:50:49 volumio volumio[1007]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 30 18:50:49 volumio volumio[1007]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 30 18:50:49 volumio volumio[1007]: info: Starting Streaming Service Transparent Proxy Jun 30 18:50:49 volumio volumio[1007]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 30 18:50:49 volumio volumio[1007]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 30 18:50:49 volumio volumio[1007]: info: Streaming services startup Jun 30 18:50:49 volumio volumio[1007]: info: Starting Streaming Daemon Jun 30 18:50:50 volumio sudo[1419]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 30 18:50:50 volumio sudo[1419]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:50 volumio volumio[1007]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 30 18:50:50 volumio sudo[1419]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:50 volumio volumio[1007]: 0+0 records in Jun 30 18:50:50 volumio volumio[1007]: 0+0 records out Jun 30 18:50:50 volumio volumio[1007]: 0 bytes copied, 0.000109276 s, 0.0 kB/s Jun 30 18:50:50 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: radio_paradise , handleBrowseUri Jun 30 18:50:50 volumio volumio[1007]: error: Cannot start Volumio Streaming Daemon Jun 30 18:50:50 volumio volumio[1007]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 30 18:50:50 volumio volumio[1007]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 30 18:50:50 volumio volumio[1007]: info: Preload queue cleared Jun 30 18:50:50 volumio volumio[1007]: STREAMING PROXY: Starting server on port 3245 Jun 30 18:50:50 volumio volumio[1007]: Node JS runtime: 14 Jun 30 18:50:50 volumio volumio[1007]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 30 18:50:51 volumio volumio[1007]: 0+0 records in Jun 30 18:50:51 volumio volumio[1007]: 0+0 records out Jun 30 18:50:51 volumio volumio[1007]: 0 bytes copied, 9.761e-05 s, 0.0 kB/s Jun 30 18:50:51 volumio volumio[1007]: info: Preload queue cleared Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::ClearQueue Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::stop Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::clearPlayQueue Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::saveQueue Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPushQueue Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::addQueueItems Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::addQueueItems Jun 30 18:50:51 volumio volumio[1007]: info: Preload queue cleared Jun 30 18:50:51 volumio volumio[1007]: info: Adding Item to queue: webrp/1 Jun 30 18:50:51 volumio volumio[1007]: info: Exploding uri webrp/1 in service radio_paradise Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPushQueue Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::saveQueue Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::updateTrackBlock Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrackBlock Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPlay Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::play index 0 Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::stop Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::play index undefined Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::startPlaybackTimer Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand stop Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand stop took 3 milliseconds Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand clear Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand clear took 2 milliseconds Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand consume 1 Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces state update: options Jun 30 18:50:51 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:50:51 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:50:51 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 8ms Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand consume 1 took 6 milliseconds Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 6ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 5ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 5ms Jun 30 18:50:51 volumio volumio[1007]: info: [1751289651487] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/mellow-flac Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/mellow-flac" Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces state update: options Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces state update: options Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces state update: options Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand status took 8 milliseconds Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand add "https://stream.radioparadise.com/mellow-flac" took 7 milliseconds Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand status took 6 milliseconds Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand status took 4 milliseconds Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand status took 3 milliseconds Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand play Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:51 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:51 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:51 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:50:51 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:51 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 33ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 39ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 38ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 37ms Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: Jun 30 18:50:51 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:51 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 55ms Jun 30 18:50:51 volumio volumio[1007]: info: sendMpdCommand play took 49 milliseconds Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 20ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 19ms Jun 30 18:50:51 volumio volumio[1007]: info: ------------------------------ 18ms Jun 30 18:50:51 volumio volumio[1007]: info: [1751289651550] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Jun 30 18:50:51 volumio volumio[1007]: info: MyVolumio token set successfully Jun 30 18:50:51 volumio volumio[1007]: info: MYVOLUMIO: Adding device Jun 30 18:50:51 volumio volumio[1007]: info: MYVOLUMIO: Evaluating Server Jun 30 18:50:52 volumio volumio[1007]: info: MyVolumio status changed Jun 30 18:50:52 volumio volumio[1007]: info: Streaming services startup Jun 30 18:50:52 volumio volumio[1007]: info: Starting Streaming Daemon Jun 30 18:50:52 volumio volumio[1007]: info: Removing browser output: myVolumio user plan is not superstar Jun 30 18:50:52 volumio volumio[1007]: info: Removing audio output: Jun 30 18:50:52 volumio volumio[1007]: info: Stoppping Tunnel 1 Jun 30 18:50:52 volumio sudo[1458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 30 18:50:52 volumio sudo[1458]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:52 volumio sudo[1461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 30 18:50:52 volumio sudo[1461]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:50:52 volumio sudo[1458]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:52 volumio volumio[1007]: 0+0 records in Jun 30 18:50:52 volumio volumio[1007]: 0+0 records out Jun 30 18:50:52 volumio volumio[1007]: 0 bytes copied, 0.000114072 s, 0.0 kB/s Jun 30 18:50:52 volumio sudo[1461]: pam_unix(sudo:session): session closed for user root Jun 30 18:50:52 volumio volumio[1007]: info: Remote SSH Stopped Jun 30 18:50:52 volumio volumio[1007]: error: Cannot start Volumio Streaming Daemon Jun 30 18:50:52 volumio volumio[1007]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 30 18:50:52 volumio volumio[1007]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 30 18:50:52 volumio volumio[1007]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 30 18:50:52 volumio volumio[1007]: info: camilladsp service terminated, instance 1 Jun 30 18:50:52 volumio volumio[1007]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 30 18:50:52 volumio volumio[1007]: info: camilladsp service started and running in background, instance 1 Jun 30 18:50:52 volumio volumio[1007]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 30 18:50:52 volumio volumio[1007]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 30 18:50:52 volumio volumio[1007]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 48 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 46 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 45 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 43 milliseconds Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 12 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 12 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 7 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 6 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 4 milliseconds Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 74ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 71ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 68ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 67ms Jun 30 18:50:52 volumio volumio[1007]: error: FusionDsp - WebSocket error: [object Object] Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 7 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 33ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 27ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 25ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 23ms Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:52 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:52 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:52 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:50:52 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:50:52 volumio volumio[1007]: info: Jun 30 18:50:52 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 8ms Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 8 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 6ms Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 5 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 4ms Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 3 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 4ms Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand status took 3 milliseconds Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 30 18:50:52 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 16ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 13ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 12ms Jun 30 18:50:52 volumio volumio[1007]: info: ------------------------------ 10ms Jun 30 18:50:52 volumio volumio[1007]: info: Setting Geolocation for MyVolumio to as2 Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:52 volumio volumio[1007]: info: [1751289652728] [RadioParadise] received new metadata: {"time":647,"artist":"Peter Gabriel","title":"In Your Eyes (live)","album":"Rare Masters","year":"1997","cover":"https://img.radioparadise.com/covers/l/B000002C4U.jpg","cover_med":"https://img.radioparadise.com/covers/m/B000002C4U.jpg","cover_small":"https://img.radioparadise.com/covers/s/B000002C4U.jpg"} Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B000002C4U.jpg","uri":"https://stream.radioparadise.com/mellow-flac","name":"In Your Eyes (live)","title":"In Your Eyes (live)","artist":"Peter Gabriel","album":"Rare Masters","streaming":true,"disableUiControls":true,"duration":652,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 30 18:50:52 volumio volumio[1007]: verbose: CURRENT POSITION 0 Jun 30 18:50:52 volumio volumio[1007]: info: CoreStateMachine::syncState stateService play Jun 30 18:50:52 volumio volumio[1007]: info: CoreStateMachine::syncState currentStatus stop Jun 30 18:50:52 volumio volumio[1007]: info: [1751289652731] [RadioParadise] setting new timer with duration of 652000 seconds. Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:52 volumio volumio[1007]: info: CorePlayQueue::getTrack 1 Jun 30 18:50:53 volumio volumio[1007]: info: Successfully Added MyVolumio device Jun 30 18:50:53 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:53 volumio volumio[1007]: 2+28 records in Jun 30 18:50:53 volumio volumio[1007]: 2+28 records out Jun 30 18:50:53 volumio volumio[1007]: 176384 bytes (176 kB, 172 KiB) copied, 0.00100786 s, 175 MB/s Jun 30 18:50:53 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:53 volumio volumio[1007]: 76+1 records in Jun 30 18:50:53 volumio volumio[1007]: 76+1 records out Jun 30 18:50:53 volumio volumio[1007]: 2518768 bytes (2.5 MB, 2.4 MiB) copied, 0.0114834 s, 219 MB/s Jun 30 18:50:53 volumio volumio[1007]: info: Updating MyVolumio device info Jun 30 18:50:53 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:53 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:53 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:50:53 volumio volumio[1007]: info: Successfully Updated MyVolumio device Jun 30 18:50:54 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:54 volumio volumio[1007]: 2+0 records in Jun 30 18:50:54 volumio volumio[1007]: 2+0 records out Jun 30 18:50:54 volumio volumio[1007]: 65536 bytes (66 kB, 64 KiB) copied, 0.000402476 s, 163 MB/s Jun 30 18:50:54 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:54 volumio volumio[1007]: 1+2 records in Jun 30 18:50:54 volumio volumio[1007]: 1+2 records out Jun 30 18:50:54 volumio volumio[1007]: 65808 bytes (66 kB, 64 KiB) copied, 0.000426624 s, 154 MB/s Jun 30 18:50:55 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:55 volumio volumio[1007]: 2+16 records in Jun 30 18:50:55 volumio volumio[1007]: 2+16 records out Jun 30 18:50:55 volumio volumio[1007]: 127936 bytes (128 kB, 125 KiB) copied, 0.000498568 s, 257 MB/s Jun 30 18:50:55 volumio volumio[1377]: .................................................................................................................++++ Jun 30 18:50:55 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:55 volumio volumio[1007]: 1+18 records in Jun 30 18:50:55 volumio volumio[1007]: 1+18 records out Jun 30 18:50:55 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000666436 s, 199 MB/s Jun 30 18:50:56 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:56 volumio volumio[1007]: 1+18 records in Jun 30 18:50:56 volumio volumio[1007]: 1+18 records out Jun 30 18:50:56 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000666602 s, 198 MB/s Jun 30 18:50:56 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:56 volumio volumio[1007]: 1+18 records in Jun 30 18:50:56 volumio volumio[1007]: 1+18 records out Jun 30 18:50:56 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000761953 s, 174 MB/s Jun 30 18:50:57 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:57 volumio volumio[1007]: 58+1 records in Jun 30 18:50:57 volumio volumio[1007]: 58+1 records out Jun 30 18:50:57 volumio volumio[1007]: 1932240 bytes (1.9 MB, 1.8 MiB) copied, 0.0088812 s, 218 MB/s Jun 30 18:50:57 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:57 volumio volumio[1007]: 1+1 records in Jun 30 18:50:57 volumio volumio[1007]: 1+1 records out Jun 30 18:50:57 volumio volumio[1007]: 61712 bytes (62 kB, 60 KiB) copied, 0.000314441 s, 196 MB/s Jun 30 18:50:58 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:58 volumio volumio[1007]: 2+14 records in Jun 30 18:50:58 volumio volumio[1007]: 2+14 records out Jun 30 18:50:58 volumio volumio[1007]: 122656 bytes (123 kB, 120 KiB) copied, 0.000454402 s, 270 MB/s Jun 30 18:50:58 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:58 volumio volumio[1007]: 1+19 records in Jun 30 18:50:58 volumio volumio[1007]: 1+19 records out Jun 30 18:50:58 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000505919 s, 261 MB/s Jun 30 18:50:58 volumio volumio[1007]: info: CoreCommandRouter::volumioPlay Jun 30 18:50:58 volumio volumio[1007]: info: CoreStateMachine::play index undefined Jun 30 18:50:58 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:50:58 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:50:59 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:59 volumio volumio[1007]: 1+18 records in Jun 30 18:50:59 volumio volumio[1007]: 1+18 records out Jun 30 18:50:59 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000509271 s, 260 MB/s Jun 30 18:50:59 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:50:59 volumio volumio[1007]: 7+1 records in Jun 30 18:50:59 volumio volumio[1007]: 7+1 records out Jun 30 18:50:59 volumio volumio[1007]: 260752 bytes (261 kB, 255 KiB) copied, 0.00137454 s, 190 MB/s Jun 30 18:51:00 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:00 volumio volumio[1007]: 1+20 records in Jun 30 18:51:00 volumio volumio[1007]: 1+20 records out Jun 30 18:51:00 volumio volumio[1007]: 136112 bytes (136 kB, 133 KiB) copied, 0.000695769 s, 196 MB/s Jun 30 18:51:00 volumio volumio[1007]: info: Preload queue cleared Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::ClearQueue Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::stop Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::stPlaybackTimer Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::updateTrackBlock Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrackBlock Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::serviceStop Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::serviceStop Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::stop Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand stop Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::clearPlayQueue Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::saveQueue Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushQueue Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::addQueueItems Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::addQueueItems Jun 30 18:51:00 volumio volumio[1007]: info: Preload queue cleared Jun 30 18:51:00 volumio volumio[1007]: info: Adding Item to queue: webrp/1 Jun 30 18:51:00 volumio volumio[1007]: info: Using cached record of: webrp/1 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushQueue Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::saveQueue Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::updateTrackBlock Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrackBlock Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPlay Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::play index 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::stop Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::play index undefined Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::startPlaybackTimer Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand stop Jun 30 18:51:00 volumio volumio[1007]: 0+0 records in Jun 30 18:51:00 volumio volumio[1007]: 0+0 records out Jun 30 18:51:00 volumio volumio[1007]: 0 bytes copied, 9.7758e-05 s, 0.0 kB/s Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand stop took 54 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand stop took 35 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: verbose: STATE SERVICE {"status":"stop","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B000002C4U.jpg","uri":"https://stream.radioparadise.com/mellow-flac","name":"In Your Eyes (live)","title":"In Your Eyes (live)","artist":"Peter Gabriel","album":"Rare Masters","streaming":true,"disableUiControls":true,"duration":652,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 30 18:51:00 volumio volumio[1007]: verbose: CURRENT POSITION 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::syncState stateService stop Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::syncState currentStatus stop Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: info: No code Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand clear Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand status took 27 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand clear took 18 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand status took 8 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand status took 8 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand status took 7 milliseconds Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand consume 1 Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:00 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:00 volumio volumio[1007]: info: CoreStateMachine::pushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jun 30 18:51:00 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:00 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 26ms Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 26ms Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 25ms Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:51:00 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:51:00 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:51:00 volumio volumio[1007]: error: updateQueue error: null Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 28ms Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 26 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand consume 1 took 26 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 7ms Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 8ms Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 7ms Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:00 volumio volumio[1007]: info: [1751289660686] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/mellow-flac Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/mellow-flac" Jun 30 18:51:00 volumio volumio[1007]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 57ms Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand add "https://stream.radioparadise.com/mellow-flac" took 4 milliseconds Jun 30 18:51:00 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand play Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: Jun 30 18:51:00 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:00 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 9ms Jun 30 18:51:00 volumio volumio[1007]: info: sendMpdCommand play took 6 milliseconds Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 5ms Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 3ms Jun 30 18:51:00 volumio volumio[1007]: info: ------------------------------ 2ms Jun 30 18:51:00 volumio volumio[1007]: info: [1751289660701] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 30 18:51:01 volumio volumio[1007]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 30 18:51:01 volumio volumio[1007]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 15 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 15 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 15 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 14 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 6 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 4 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 3 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 2 milliseconds Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 29ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 28ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 28ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 27ms Jun 30 18:51:01 volumio volumio[1007]: error: FusionDsp - WebSocket error: [object Object] Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 18ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 16ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 15ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 14ms Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:01 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:01 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:01 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 6ms Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 6 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 6ms Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 4 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 4ms Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 2 milliseconds Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces system playlist update Jun 30 18:51:01 volumio volumio[1007]: info: Ignoring MPD Status Update Jun 30 18:51:01 volumio volumio[1007]: info: Jun 30 18:51:01 volumio volumio[1007]: ---------------------------- MPD announces state update: player Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::getState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand status Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 8 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 9 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 9 milliseconds Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 8ms Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand status took 2 milliseconds Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseState Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 20ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 18ms Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 16ms Jun 30 18:51:01 volumio volumio[1007]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 30 18:51:01 volumio volumio[1007]: verbose: ControllerMpd::parseTrackInfo Jun 30 18:51:01 volumio volumio[1007]: info: ControllerMpd::pushState Jun 30 18:51:01 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:01 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:01 volumio volumio[1007]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Jun 30 18:51:01 volumio volumio[1007]: info: ------------------------------ 15ms Jun 30 18:51:01 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:01 volumio volumio[1007]: 18+1 records in Jun 30 18:51:01 volumio volumio[1007]: 18+1 records out Jun 30 18:51:01 volumio volumio[1007]: 619312 bytes (619 kB, 605 KiB) copied, 0.00322431 s, 192 MB/s Jun 30 18:51:01 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:01 volumio volumio[1007]: 10+1 records in Jun 30 18:51:01 volumio volumio[1007]: 10+1 records out Jun 30 18:51:01 volumio volumio[1007]: 356896 bytes (357 kB, 349 KiB) copied, 0.00201897 s, 177 MB/s Jun 30 18:51:02 volumio volumio[1007]: info: [1751289662278] [RadioParadise] received new metadata: {"time":637,"artist":"Peter Gabriel","title":"In Your Eyes (live)","album":"Rare Masters","year":"1997","cover":"https://img.radioparadise.com/covers/l/B000002C4U.jpg","cover_med":"https://img.radioparadise.com/covers/m/B000002C4U.jpg","cover_small":"https://img.radioparadise.com/covers/s/B000002C4U.jpg"} Jun 30 18:51:02 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:02 volumio volumio[1007]: info: CoreCommandRouter::servicePushState Jun 30 18:51:02 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:02 volumio volumio[1007]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B000002C4U.jpg","uri":"https://stream.radioparadise.com/mellow-flac","name":"In Your Eyes (live)","title":"In Your Eyes (live)","artist":"Peter Gabriel","album":"Rare Masters","streaming":true,"disableUiControls":true,"duration":642,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jun 30 18:51:02 volumio volumio[1007]: verbose: CURRENT POSITION 0 Jun 30 18:51:02 volumio volumio[1007]: info: CoreStateMachine::syncState stateService play Jun 30 18:51:02 volumio volumio[1007]: info: CoreStateMachine::syncState currentStatus stop Jun 30 18:51:02 volumio volumio[1007]: info: [1751289662280] [RadioParadise] setting new timer with duration of 642000 seconds. Jun 30 18:51:02 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:02 volumio volumio[1007]: info: CorePlayQueue::getTrack 1 Jun 30 18:51:02 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:02 volumio volumio[1007]: 64+1 records in Jun 30 18:51:02 volumio volumio[1007]: 64+1 records out Jun 30 18:51:02 volumio volumio[1007]: 2129088 bytes (2.1 MB, 2.0 MiB) copied, 0.0123452 s, 172 MB/s Jun 30 18:51:02 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:02 volumio volumio[1007]: 11+1 records in Jun 30 18:51:02 volumio volumio[1007]: 11+1 records out Jun 30 18:51:02 volumio volumio[1007]: 389664 bytes (390 kB, 381 KiB) copied, 0.00222636 s, 175 MB/s Jun 30 18:51:03 volumio systemd[1]: systemd-timedated.service: Succeeded. Jun 30 18:51:03 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:03 volumio volumio[1007]: 1+27 records in Jun 30 18:51:03 volumio volumio[1007]: 1+27 records out Jun 30 18:51:03 volumio volumio[1007]: 165008 bytes (165 kB, 161 KiB) copied, 0.00055903 s, 295 MB/s Jun 30 18:51:03 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:03 volumio volumio[1007]: 1+18 records in Jun 30 18:51:03 volumio volumio[1007]: 1+18 records out Jun 30 18:51:03 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000654973 s, 202 MB/s Jun 30 18:51:03 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 30 18:51:03 volumio volumio[1007]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 30 18:51:03 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jun 30 18:51:03 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jun 30 18:51:04 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:04 volumio volumio[1007]: 1+2 records in Jun 30 18:51:04 volumio volumio[1007]: 1+2 records out Jun 30 18:51:04 volumio volumio[1007]: 68672 bytes (69 kB, 67 KiB) copied, 0.00037005 s, 186 MB/s Jun 30 18:51:04 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:04 volumio volumio[1007]: 24+1 records in Jun 30 18:51:04 volumio volumio[1007]: 24+1 records out Jun 30 18:51:04 volumio volumio[1007]: 815584 bytes (816 kB, 796 KiB) copied, 0.00402362 s, 203 MB/s Jun 30 18:51:05 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:05 volumio volumio[1007]: 2+28 records in Jun 30 18:51:05 volumio volumio[1007]: 2+28 records out Jun 30 18:51:05 volumio volumio[1007]: 174048 bytes (174 kB, 170 KiB) copied, 0.000597437 s, 291 MB/s Jun 30 18:51:05 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:05 volumio volumio[1007]: 1+18 records in Jun 30 18:51:05 volumio volumio[1007]: 1+18 records out Jun 30 18:51:05 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000639511 s, 207 MB/s Jun 30 18:51:06 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:06 volumio volumio[1007]: 1+18 records in Jun 30 18:51:06 volumio volumio[1007]: 1+18 records out Jun 30 18:51:06 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000495938 s, 267 MB/s Jun 30 18:51:06 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:06 volumio volumio[1007]: 1+19 records in Jun 30 18:51:06 volumio volumio[1007]: 1+19 records out Jun 30 18:51:06 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000504457 s, 262 MB/s Jun 30 18:51:07 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:07 volumio volumio[1007]: 1+18 records in Jun 30 18:51:07 volumio volumio[1007]: 1+18 records out Jun 30 18:51:07 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000501086 s, 264 MB/s Jun 30 18:51:07 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:07 volumio volumio[1007]: 1+18 records in Jun 30 18:51:07 volumio volumio[1007]: 1+18 records out Jun 30 18:51:07 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000524863 s, 252 MB/s Jun 30 18:51:07 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 30 18:51:07 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:51:07 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 30 18:51:08 volumio volumio-remote-updater[604]: No test mode Jun 30 18:51:08 volumio volumio-remote-updater[604]: No alpha test mode Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 30 18:51:08 volumio volumio[1007]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

    • Various Fixes for QOBUZ Connect
    • Various Fixes for Tidal Connect



 

","title":"Update v3.816","updateavailable":true} Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 30 18:51:08 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:08 volumio volumio[1007]: 1+18 records in Jun 30 18:51:08 volumio volumio[1007]: 1+18 records out Jun 30 18:51:08 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000520697 s, 254 MB/s Jun 30 18:51:08 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:08 volumio volumio[1007]: 1+19 records in Jun 30 18:51:08 volumio volumio[1007]: 1+19 records out Jun 30 18:51:08 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000509901 s, 259 MB/s Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::volumioGetBrowseSources Jun 30 18:51:08 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 30 18:51:09 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:09 volumio volumio[1007]: 1+18 records in Jun 30 18:51:09 volumio volumio[1007]: 1+18 records out Jun 30 18:51:09 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000498735 s, 265 MB/s Jun 30 18:51:10 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:10 volumio volumio[1007]: 1+18 records in Jun 30 18:51:10 volumio volumio[1007]: 1+18 records out Jun 30 18:51:10 volumio volumio[1007]: 132288 bytes (132 kB, 129 KiB) copied, 0.000706639 s, 187 MB/s Jun 30 18:51:10 volumio volumio[1007]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 30 18:51:10 volumio volumio[1007]: info: Completed starting MyVolumio Plugin Jun 30 18:51:10 volumio volumio[1007]: [Metrics] CommandRouter: 37s 381.37ms Jun 30 18:51:10 volumio volumio[1007]: info: CoreCommandRouter::volumiosetStartupVolume Jun 30 18:51:10 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 30 18:51:10 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 30 18:51:10 volumio volumio[1007]: info: CoreCommandRouter::Close All Modals sent Jun 30 18:51:10 volumio volumio[1007]: info: CoreCommandRouter::Close All Modals sent Jun 30 18:51:10 volumio volumio[1007]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 30 18:51:10 volumio volumio[1007]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 30 18:51:10 volumio volumio[1007]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 30 18:51:10 volumio volumio[1007]: error: FusionDsp - WebSocket error: [object Object] Jun 30 18:51:10 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:10 volumio volumio[1007]: 1+20 records in Jun 30 18:51:10 volumio volumio[1007]: 1+20 records out Jun 30 18:51:10 volumio volumio[1007]: 210112 bytes (210 kB, 205 KiB) copied, 0.000698806 s, 301 MB/s Jun 30 18:51:11 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 30 18:51:11 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 30 18:51:11 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 30 18:51:11 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:11 volumio volumio[1007]: 1+19 records in Jun 30 18:51:11 volumio volumio[1007]: 1+19 records out Jun 30 18:51:11 volumio volumio[1007]: 133248 bytes (133 kB, 130 KiB) copied, 0.000856693 s, 156 MB/s Jun 30 18:51:11 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:11 volumio volumio[1007]: 2+17 records in Jun 30 18:51:11 volumio volumio[1007]: 2+17 records out Jun 30 18:51:11 volumio volumio[1007]: 190864 bytes (191 kB, 186 KiB) copied, 0.000664232 s, 287 MB/s Jun 30 18:51:12 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:12 volumio volumio[1007]: 26+1 records in Jun 30 18:51:12 volumio volumio[1007]: 26+1 records out Jun 30 18:51:12 volumio volumio[1007]: 882304 bytes (882 kB, 862 KiB) copied, 0.00552884 s, 160 MB/s Jun 30 18:51:12 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:12 volumio volumio[1007]: 44+29 records in Jun 30 18:51:12 volumio volumio[1007]: 44+29 records out Jun 30 18:51:12 volumio volumio[1007]: 1556880 bytes (1.6 MB, 1.5 MiB) copied, 0.00710815 s, 219 MB/s Jun 30 18:51:13 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:13 volumio volumio[1007]: 1+41 records in Jun 30 18:51:13 volumio volumio[1007]: 1+41 records out Jun 30 18:51:13 volumio volumio[1007]: 377888 bytes (378 kB, 369 KiB) copied, 0.00103397 s, 365 MB/s Jun 30 18:51:13 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:13 volumio volumio[1007]: 2+16 records in Jun 30 18:51:13 volumio volumio[1007]: 2+16 records out Jun 30 18:51:13 volumio volumio[1007]: 181600 bytes (182 kB, 177 KiB) copied, 0.000636992 s, 285 MB/s Jun 30 18:51:14 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:14 volumio volumio[1007]: 1+16 records in Jun 30 18:51:14 volumio volumio[1007]: 1+16 records out Jun 30 18:51:14 volumio volumio[1007]: 127072 bytes (127 kB, 124 KiB) copied, 0.000530252 s, 240 MB/s Jun 30 18:51:15 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:15 volumio volumio[1007]: 14+1 records in Jun 30 18:51:15 volumio volumio[1007]: 14+1 records out Jun 30 18:51:15 volumio volumio[1007]: 486768 bytes (487 kB, 475 KiB) copied, 0.00260276 s, 187 MB/s Jun 30 18:51:15 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:15 volumio volumio[1007]: 4+1 records in Jun 30 18:51:15 volumio volumio[1007]: 4+1 records out Jun 30 18:51:15 volumio volumio[1007]: 160016 bytes (160 kB, 156 KiB) copied, 0.000888822 s, 180 MB/s Jun 30 18:51:16 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:16 volumio volumio[1007]: 5+1 records in Jun 30 18:51:16 volumio volumio[1007]: 5+1 records out Jun 30 18:51:16 volumio volumio[1007]: 192784 bytes (193 kB, 188 KiB) copied, 0.00100043 s, 193 MB/s Jun 30 18:51:16 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:16 volumio volumio[1007]: 8+1 records in Jun 30 18:51:16 volumio volumio[1007]: 8+1 records out Jun 30 18:51:16 volumio volumio[1007]: 291088 bytes (291 kB, 284 KiB) copied, 0.00153124 s, 190 MB/s Jun 30 18:51:17 volumio volumio[1007]: info: BOOT COMPLETED Jun 30 18:51:17 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:17 volumio volumio[1007]: 4+1 records in Jun 30 18:51:17 volumio volumio[1007]: 4+1 records out Jun 30 18:51:17 volumio volumio[1007]: 160016 bytes (160 kB, 156 KiB) copied, 0.000845378 s, 189 MB/s Jun 30 18:51:17 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:17 volumio volumio[1007]: 4+1 records in Jun 30 18:51:17 volumio volumio[1007]: 4+1 records out Jun 30 18:51:17 volumio volumio[1007]: 160016 bytes (160 kB, 156 KiB) copied, 0.000851007 s, 188 MB/s Jun 30 18:51:18 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:18 volumio volumio[1007]: 1+20 records in Jun 30 18:51:18 volumio volumio[1007]: 1+20 records out Jun 30 18:51:18 volumio volumio[1007]: 136768 bytes (137 kB, 134 KiB) copied, 0.000727009 s, 188 MB/s Jun 30 18:51:18 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:18 volumio volumio[1007]: 7+1 records in Jun 30 18:51:18 volumio volumio[1007]: 7+1 records out Jun 30 18:51:18 volumio volumio[1007]: 261088 bytes (261 kB, 255 KiB) copied, 0.00138089 s, 189 MB/s Jun 30 18:51:19 volumio ntpd[805]: Soliciting pool server 103.189.191.36 Jun 30 18:51:19 volumio ntpd[805]: Soliciting pool server 192.46.210.39 Jun 30 18:51:19 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:19 volumio volumio[1007]: 1+20 records in Jun 30 18:51:19 volumio volumio[1007]: 1+20 records out Jun 30 18:51:19 volumio volumio[1007]: 135776 bytes (136 kB, 133 KiB) copied, 0.000510456 s, 266 MB/s Jun 30 18:51:19 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:19 volumio volumio[1007]: 5+1 records in Jun 30 18:51:19 volumio volumio[1007]: 5+1 records out Jun 30 18:51:19 volumio volumio[1007]: 196544 bytes (197 kB, 192 KiB) copied, 0.000998636 s, 197 MB/s Jun 30 18:51:19 volumio ntpd[805]: Soliciting pool server 17.253.18.131 Jun 30 18:51:19 volumio ntpd[805]: Soliciting pool server 160.250.111.199 Jun 30 18:51:19 volumio ntpd[805]: Soliciting pool server 194.0.5.123 Jun 30 18:51:20 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:20 volumio volumio[1007]: 9+1 records in Jun 30 18:51:20 volumio volumio[1007]: 9+1 records out Jun 30 18:51:20 volumio volumio[1007]: 324128 bytes (324 kB, 317 KiB) copied, 0.00180505 s, 180 MB/s Jun 30 18:51:20 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:20 volumio volumio[1007]: 2+1 records in Jun 30 18:51:20 volumio volumio[1007]: 2+1 records out Jun 30 18:51:20 volumio volumio[1007]: 94480 bytes (94 kB, 92 KiB) copied, 0.000473105 s, 200 MB/s Jun 30 18:51:20 volumio ntpd[805]: Soliciting pool server 162.159.200.123 Jun 30 18:51:20 volumio ntpd[805]: Soliciting pool server 13.200.20.166 Jun 30 18:51:21 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:21 volumio volumio[1007]: 10+1 records in Jun 30 18:51:21 volumio volumio[1007]: 10+1 records out Jun 30 18:51:21 volumio volumio[1007]: 352800 bytes (353 kB, 345 KiB) copied, 0.00192942 s, 183 MB/s Jun 30 18:51:21 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:21 volumio volumio[1007]: 4+0 records in Jun 30 18:51:21 volumio volumio[1007]: 4+0 records out Jun 30 18:51:21 volumio volumio[1007]: 131072 bytes (131 kB, 128 KiB) copied, 0.000620752 s, 211 MB/s Jun 30 18:51:21 volumio ntpd[805]: Soliciting pool server 86.107.100.245 Jun 30 18:51:21 volumio ntpd[805]: Soliciting pool server 139.59.15.185 Jun 30 18:51:22 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:22 volumio volumio[1007]: 7+1 records in Jun 30 18:51:22 volumio volumio[1007]: 7+1 records out Jun 30 18:51:22 volumio volumio[1007]: 258592 bytes (259 kB, 253 KiB) copied, 0.00147146 s, 176 MB/s Jun 30 18:51:22 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:22 volumio volumio[1007]: 3+1 records in Jun 30 18:51:22 volumio volumio[1007]: 3+1 records out Jun 30 18:51:22 volumio volumio[1007]: 127248 bytes (127 kB, 124 KiB) copied, 0.000640973 s, 199 MB/s Jun 30 18:51:22 volumio ntpd[805]: Soliciting pool server 139.84.137.53 Jun 30 18:51:22 volumio ntpd[805]: Soliciting pool server 162.159.200.1 Jun 30 18:51:23 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:23 volumio volumio[1007]: 8+1 records in Jun 30 18:51:23 volumio volumio[1007]: 8+1 records out Jun 30 18:51:23 volumio volumio[1007]: 291088 bytes (291 kB, 284 KiB) copied, 0.00157128 s, 185 MB/s Jun 30 18:51:23 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:23 volumio volumio[1007]: 11+1 records in Jun 30 18:51:23 volumio volumio[1007]: 11+1 records out Jun 30 18:51:23 volumio volumio[1007]: 385840 bytes (386 kB, 377 KiB) copied, 0.00221001 s, 175 MB/s Jun 30 18:51:23 volumio ntpd[805]: Soliciting pool server 139.84.142.141 Jun 30 18:51:23 volumio ntpd[805]: Soliciting pool server 3.6.43.90 Jun 30 18:51:24 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:24 volumio volumio[1007]: 5+0 records in Jun 30 18:51:24 volumio volumio[1007]: 5+0 records out Jun 30 18:51:24 volumio volumio[1007]: 163840 bytes (164 kB, 160 KiB) copied, 0.00080873 s, 203 MB/s Jun 30 18:51:24 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:24 volumio volumio[1007]: 4+1 records in Jun 30 18:51:24 volumio volumio[1007]: 4+1 records out Jun 30 18:51:24 volumio volumio[1007]: 162048 bytes (162 kB, 158 KiB) copied, 0.000858452 s, 189 MB/s Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:51:24 volumio volumio[1007]: info: Retrieving Cloud Streaming UI Jun 30 18:51:24 volumio volumio[1007]: info: Getting Tidal Cloud Configuration Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:51:24 volumio volumio[1007]: info: Getting Qobuz Cloud Configuration Jun 30 18:51:24 volumio volumio[1007]: info: Asking plugin for UI Config Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:51:24 volumio volumio[1007]: info: Getting Spotify Cloud Configuration Jun 30 18:51:24 volumio volumio[1007]: info: Asking plugin for UI Config Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:51:24 volumio volumio[1007]: info: Saving Spotify Acccount Jun 30 18:51:24 volumio volumio[1007]: info: Got Tidal Cloud Configuration Jun 30 18:51:24 volumio volumio[1007]: info: Got it Jun 30 18:51:24 volumio volumio[1007]: info: Got it Jun 30 18:51:24 volumio volumio[1007]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 30 18:51:24 volumio volumio[1007]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::volumioGetBrowseSources Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 30 18:51:24 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 30 18:51:24 volumio ntpd[805]: Soliciting pool server 14.139.60.107 Jun 30 18:51:24 volumio ntpd[805]: Soliciting pool server 103.189.191.15 Jun 30 18:51:25 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:25 volumio volumio[1007]: 1+14 records in Jun 30 18:51:25 volumio volumio[1007]: 1+14 records out Jun 30 18:51:25 volumio volumio[1007]: 113984 bytes (114 kB, 111 KiB) copied, 0.000485679 s, 235 MB/s Jun 30 18:51:25 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:25 volumio volumio[1007]: 5+1 records in Jun 30 18:51:25 volumio volumio[1007]: 5+1 records out Jun 30 18:51:25 volumio volumio[1007]: 195824 bytes (196 kB, 191 KiB) copied, 0.000995468 s, 197 MB/s Jun 30 18:51:25 volumio ntpd[805]: Soliciting pool server 160.250.111.199 Jun 30 18:51:26 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:26 volumio volumio[1007]: 10+1 records in Jun 30 18:51:26 volumio volumio[1007]: 10+1 records out Jun 30 18:51:26 volumio volumio[1007]: 356896 bytes (357 kB, 349 KiB) copied, 0.0019247 s, 185 MB/s Jun 30 18:51:26 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:26 volumio volumio[1007]: 5+1 records in Jun 30 18:51:26 volumio volumio[1007]: 5+1 records out Jun 30 18:51:26 volumio volumio[1007]: 192784 bytes (193 kB, 188 KiB) copied, 0.000986617 s, 195 MB/s Jun 30 18:51:27 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:27 volumio volumio[1007]: 7+1 records in Jun 30 18:51:27 volumio volumio[1007]: 7+1 records out Jun 30 18:51:27 volumio volumio[1007]: 254496 bytes (254 kB, 249 KiB) copied, 0.00139408 s, 183 MB/s Jun 30 18:51:27 volumio volumio[1007]: info: Disabling MyMusic plugin upnp Jun 30 18:51:27 volumio sudo[1997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jun 30 18:51:27 volumio sudo[1997]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 30 18:51:27 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Jun 30 18:51:27 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:27 volumio volumio[1007]: 2+20 records in Jun 30 18:51:27 volumio volumio[1007]: 2+20 records out Jun 30 18:51:27 volumio volumio[1007]: 146496 bytes (146 kB, 143 KiB) copied, 0.00049553 s, 296 MB/s Jun 30 18:51:28 volumio ntpd[805]: receive: Unexpected origin timestamp 0xec0d0dd7.e3f7c8b9 does not match aorg 0000000000.00000000 from server@14.139.60.107 xmt 0xec0d0dd8.d91f9faf Jun 30 18:51:28 volumio ntpd[805]: receive: Unexpected origin timestamp 0xec0d0dd7.e406f45e does not match aorg 0000000000.00000000 from server@103.189.191.36 xmt 0xec0d0dd8.dc3580fa Jun 30 18:51:29 volumio volumio[1007]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Jun 30 18:51:29 volumio volumio[1007]: 3+1 records in Jun 30 18:51:29 volumio volumio[1007]: 3+1 records out Jun 30 18:51:29 volumio volumio[1007]: 130112 bytes (130 kB, 127 KiB) copied, 0.000676751 s, 192 MB/s Jun 30 18:51:29 volumio volumio[1007]: info: Enabling MyMusic plugin upnp Jun 30 18:51:29 volumio volumio[1007]: info: Enabling plugin upnp Jun 30 18:51:29 volumio volumio[1007]: info: Loading plugin "upnp"... Jun 30 18:51:29 volumio volumio[1007]: info: [1751289689557] Starting Upmpd Daemon Jun 30 18:51:29 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 30 18:51:29 volumio volumio[1007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 30 18:51:29 volumio volumio[1007]: Error: listen EADDRINUSE: address already in use :::6599 Jun 30 18:51:29 volumio volumio[1007]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Jun 30 18:51:29 volumio volumio[1007]: at listenInCluster (net.js:1366:12) Jun 30 18:51:29 volumio volumio[1007]: at Server.listen (net.js:1452:7) Jun 30 18:51:29 volumio volumio[1007]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jun 30 18:51:29 volumio volumio[1007]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jun 30 18:51:29 volumio volumio[1007]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jun 30 18:51:29 volumio volumio[1007]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 30 18:51:29 volumio volumio[1007]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Jun 30 18:51:29 volumio volumio[1007]: code: 'EADDRINUSE', Jun 30 18:51:29 volumio volumio[1007]: errno: -98, Jun 30 18:51:29 volumio volumio[1007]: syscall: 'listen', Jun 30 18:51:29 volumio volumio[1007]: address: '::', Jun 30 18:51:29 volumio volumio[1007]: port: 6599 Jun 30 18:51:29 volumio volumio[1007]: } Jun 30 18:51:29 volumio volumio[1007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 30 18:51:29 volumio sudo[2034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-30 18:50 Jun 30 18:51:29 volumio sudo[2034]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"