-- Logs begin at Sat 2025-05-24 09:01:50 EEST, end at Sat 2025-05-24 09:03:03 EEST. -- May 24 09:02:00 volumio sudo[1415]: pam_unix(sudo:session): session closed for user root May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "upnp_browser"... May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "alarm-clock"... May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "airplay_emulation"... May 24 09:02:00 volumio volumio[1072]: info: Starting Shairport Sync May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "last_100"... May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "webradio"... May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "i2s_dacs"... May 24 09:02:00 volumio volumio[1072]: info: I2S DAC not set, start Auto-detection May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "volumiodiscovery"... May 24 09:02:00 volumio volumio[1072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 24 09:02:00 volumio volumio[1072]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:02:00 volumio volumio[1072]: *** WARNING *** For more information see May 24 09:02:00 volumio volumio[1072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 24 09:02:00 volumio volumio[1072]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:02:00 volumio node[1072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 24 09:02:00 volumio volumio[1072]: *** WARNING *** For more information see May 24 09:02:00 volumio node[1072]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:02:00 volumio node[1072]: *** WARNING *** For more information see May 24 09:02:00 volumio node[1072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 24 09:02:00 volumio node[1072]: *** WARNING *** Please fix your application to use the native API of Avahi! May 24 09:02:00 volumio node[1072]: *** WARNING *** For more information see May 24 09:02:00 volumio volumio[1072]: info: Applying required configuration parameters for plugin volumiodiscovery May 24 09:02:00 volumio volumio[1072]: info: Discovery: Started advertising with name: Volumio May 24 09:02:00 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 24 09:02:00 volumio volumio[1072]: info: Loading plugin "spop"... May 24 09:02:01 volumio volumio[1072]: info: Loading plugin "youtube2"... May 24 09:02:01 volumio volumio-time-update[741]: volumio-time-update-util: Fetching time from Volumio... May 24 09:02:01 volumio sudo[1398]: pam_unix(sudo:session): session closed for user root May 24 09:02:01 volumio volumio-time-update[741]: volumio-time-update-util: Setting system time to: 2025-05-24 09:02:01 May 24 09:02:01 volumio sudo[1510]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-24 09:02:01 May 24 09:02:01 volumio sudo[1510]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:01 volumio dbus-daemon[742]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.12' (uid=0 pid=1511 comm="timedatectl set-time 2025-05-24 09:02:01 ") May 24 09:02:01 volumio systemd[1]: Starting Time & Date Service... May 24 09:02:01 volumio dbus-daemon[742]: [system] Successfully activated service 'org.freedesktop.timedate1' May 24 09:02:01 volumio systemd[1]: Started Time & Date Service. May 24 09:02:01 volumio systemd-timedated[1512]: Changed local time to Sat May 24 09:02:01 2025 May 24 09:02:01 volumio sudo[1510]: pam_unix(sudo:session): session closed for user root May 24 09:02:01 volumio volumio-time-update[741]: volumio-time-update-util: System time updated successfully. May 24 09:02:01 volumio systemd[1]: Started Volumio Time Update Utility. May 24 09:02:01 volumio volumio[1072]: info: Loading plugin "ytmusic"... May 24 09:02:01 volumio nmbd[982]: [2025/05/24 09:02:01.665310, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 24 09:02:01 volumio nmbd[982]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 24 09:02:01 volumio systemd[1]: Started Samba NMB Daemon. May 24 09:02:01 volumio systemd[1]: Starting Samba Winbind Daemon... May 24 09:02:01 volumio winbindd[1514]: [2025/05/24 09:02:01.789158, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 24 09:02:01 volumio winbindd[1514]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 24 09:02:01 volumio winbindd[1514]: [2025/05/24 09:02:01.791441, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 24 09:02:01 volumio winbindd[1514]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 24 09:02:01 volumio systemd[1]: Started Samba Winbind Daemon. May 24 09:02:01 volumio systemd[1]: Starting Samba SMB Daemon... May 24 09:02:01 volumio volumio[1072]: info: Loading plugin "now_playing"... May 24 09:02:01 volumio winbindd[1514]: [2025/05/24 09:02:01.978470, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) May 24 09:02:01 volumio winbindd[1514]: res_names->count = 3, expected 4 May 24 09:02:01 volumio smbd[1519]: [2025/05/24 09:02:01.993077, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 24 09:02:01 volumio smbd[1519]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 24 09:02:01 volumio systemd[1]: Started Samba SMB Daemon. May 24 09:02:01 volumio systemd[1]: Reached target Multi-User System. May 24 09:02:01 volumio systemd[1]: Reached target Graphical Interface. May 24 09:02:02 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 24 09:02:02 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 24 09:02:02 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 24 09:02:02 volumio systemd[1]: Startup finished in 6.321s (kernel) + 13.229s (userspace) = 19.551s. May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "peppy_screensaver"... May 24 09:02:02 volumio volumio[1072]: info: Applying required configuration parameters for plugin peppy_screensaver May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "outputs"... May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "albumart"... May 24 09:02:02 volumio volumio[1072]: info: Plugin example_plugin is not enabled May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "inputs"... May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "updater_comm"... May 24 09:02:02 volumio dhcpcd[907]: eth0: leased 192.168.0.252 for 300 seconds May 24 09:02:02 volumio dhcpcd[907]: eth0: adding route to 192.168.0.0/24 May 24 09:02:02 volumio dhcpcd[907]: eth0: adding default route via 192.168.0.1 May 24 09:02:02 volumio volumio[1072]: Forking 3 albumart workers May 24 09:02:02 volumio volumio[1072]: info: Plugin mpdemulation is not enabled May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "rest_api"... May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "websocket"... May 24 09:02:02 volumio volumio[1072]: info: Starting Socket.io Server version 2.3.0 May 24 09:02:02 volumio volumio[1072]: info: Loading plugin "backup_restore"... May 24 09:02:02 volumio systemd[1]: Stopping Network Time Service... May 24 09:02:02 volumio ntpd[1357]: ntpd exiting on signal 15 (Terminated) May 24 09:02:02 volumio ntpd[1357]: 185.53.79.3 local addr 192.168.0.252 -> May 24 09:02:02 volumio systemd[1]: ntp.service: Succeeded. May 24 09:02:02 volumio systemd[1]: Stopped Network Time Service. May 24 09:02:02 volumio systemd[1]: Starting Network Time Service... May 24 09:02:02 volumio ntpd[1593]: ntpd 4.2.8p12@1.3728-o (1): Starting May 24 09:02:02 volumio ntpd[1593]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 104:103 May 24 09:02:02 volumio systemd[1]: Started Network Time Service. May 24 09:02:02 volumio ntpd[1599]: proto: precision = 0.117 usec (-23) May 24 09:02:02 volumio ntpd[1599]: Listen and drop on 0 v6wildcard [::]:123 May 24 09:02:02 volumio ntpd[1599]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 24 09:02:02 volumio ntpd[1599]: Listen normally on 2 lo 127.0.0.1:123 May 24 09:02:02 volumio ntpd[1599]: Listen normally on 3 eth0 192.168.0.252:123 May 24 09:02:02 volumio ntpd[1599]: Listening on routing socket on fd #20 for interface updates May 24 09:02:02 volumio ntpd[1599]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 24 09:02:02 volumio ntpd[1599]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 24 09:02:02 volumio volumio[1072]: info: Applying required configuration parameters for plugin backup_restore May 24 09:02:02 volumio volumio[1072]: info: Loading i18n strings for locale ua May 24 09:02:02 volumio volumio[1072]: Updating browse sources language May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:02 volumio volumio[1072]: Starting albumart workers May 24 09:02:02 volumio volumio[1072]: Starting albumart workers May 24 09:02:02 volumio volumio[1072]: Starting albumart workers May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::initPlayerControls May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 24 09:02:02 volumio volumio[1072]: Express server listening on port 3000 May 24 09:02:02 volumio volumio[1072]: [Metrics] WebUI: 6s 529.49ms May 24 09:02:02 volumio volumio[1072]: info: Setting Device type: x86 May 24 09:02:02 volumio volumio[1072]: info: CoreStateMachine::resetVolumioState May 24 09:02:02 volumio volumio[1072]: info: CoreStateMachine::getcurrentVolume May 24 09:02:02 volumio volumio[1072]: info: CoreCommandRouter::volumioRetrievevolume May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio volumio[1072]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 24 09:02:03 volumio volumio[1072]: info: Completed loading Core Plugins May 24 09:02:03 volumio volumio[1072]: info: Preparing to generate the ALSA configuration file May 24 09:02:03 volumio volumio[1072]: info: Volumio Network Manager: Network status updated: 1 May 24 09:02:03 volumio volumio[1072]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 24 09:02:03 volumio volumio[1072]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf May 24 09:02:03 volumio volumio[1072]: info: Reading ALSA contributions from plugins. May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 24 09:02:03 volumio volumio[1072]: info: Reloading queue from file May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::setRepeat true single undefined May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::setRandom null May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:03 volumio volumio[1072]: info: VolumeController:: Volume=100 Mute =false May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioRetrievevolume May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 May 24 09:02:03 volumio volumio[1072]: info: VolumeController:: Volume=100 Mute =false May 24 09:02:03 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:03 volumio volumio[1072]: info: Asound.conf file unchanged, so no further update is needed May 24 09:02:03 volumio volumio[1072]: info: Output device has changed, restarting MPD May 24 09:02:03 volumio sudo[1635]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 24 09:02:03 volumio sudo[1635]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio sudo[1635]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: Output device has changed, restarting Shairport Sync May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio sudo[1638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 24 09:02:03 volumio sudo[1638]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio systemd[1]: Stopping Music Player Daemon... May 24 09:02:03 volumio volumio[1072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:02:03 volumio volumio[1072]: info: ___________ START PLUGINS ___________ May 24 09:02:03 volumio volumio[1072]: info: ControllerMpd::onStart: Initializing MPD May 24 09:02:03 volumio volumio[1072]: info: Creating MPD Configuration file May 24 09:02:03 volumio sudo[1644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 24 09:02:03 volumio sudo[1644]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio sudo[1644]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:02:03 volumio volumio[1072]: info: [1748066523348] CoreMusicLibrary::Adding element Media Servers May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:03 volumio sudo[1647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 24 09:02:03 volumio systemd[1]: mpd.service: Succeeded. May 24 09:02:03 volumio sudo[1647]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio systemd[1]: Stopped Music Player Daemon. May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio systemd[1]: Starting Music Player Daemon... May 24 09:02:03 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 24 09:02:03 volumio systemd[1]: mpd.service: Succeeded. May 24 09:02:03 volumio systemd[1]: Stopped Music Player Daemon. May 24 09:02:03 volumio systemd[1]: Starting Music Player Daemon... May 24 09:02:03 volumio volumio[1072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:02:03 volumio volumio[1072]: info: [1748066523407] CoreMusicLibrary::Adding element Last_100 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:02:03 volumio volumio[1072]: info: [1748066523408] CoreMusicLibrary::Adding element Webradio May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:02:03 volumio volumio[1072]: info: Initializing BBC Radios May 24 09:02:03 volumio sudo[1656]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 24 09:02:03 volumio sudo[1656]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio sudo[1656]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: Creating Spotify config file May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:02:03 volumio volumio[1072]: info: [1748066523488] CoreMusicLibrary::Adding element YouTube2 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:03 volumio volumio[1072]: Cannot find translation for source YouTube2 May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:02:03 volumio volumio[1072]: info: [1748066523491] CoreMusicLibrary::Adding element YouTube Music May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:03 volumio volumio[1072]: Cannot find translation for source YouTube2 May 24 09:02:03 volumio volumio[1072]: Cannot find translation for source YouTube Music May 24 09:02:03 volumio volumio[1072]: info: [now-playing] ConfigUpdater: config is up to date. May 24 09:02:03 volumio volumio[1072]: info: Loading i18n strings for locale ua May 24 09:02:03 volumio volumio[1072]: info: /tmp/myfifo created May 24 09:02:03 volumio volumio[1072]: info: /tmp/myfifosa created May 24 09:02:03 volumio sudo[1674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 May 24 09:02:03 volumio sudo[1674]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio sudo[1674]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: snd-dummy loaded May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio sudo[1695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/shairport-sync.conf.tmpl /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl May 24 09:02:03 volumio sudo[1695]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio sudo[1695]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 24 09:02:03 volumio volumio[1072]: info: Volumio Calling Home May 24 09:02:03 volumio volumio[1072]: info: [now-playing] App is listening on port 4004. May 24 09:02:03 volumio volumio[1072]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds May 24 09:02:03 volumio volumio[1072]: info: Discovery: adding 0cab30ac-6f0e-4e11-9f93-957eae730792 May 24 09:02:03 volumio volumio[1072]: info: Discovery: Found device Volumio May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:03 volumio volumio[1072]: info: MPD Permissions set May 24 09:02:03 volumio volumio[1072]: info: MPD Permissions set May 24 09:02:03 volumio volumio[1072]: info: Spotify config file written May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:03 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 May 24 09:02:03 volumio sudo[1703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio sudo[1703]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 24 09:02:03 volumio systemd[1]: Started go-librespot Daemon. May 24 09:02:03 volumio go-librespot[1706]: go-librespot daemon starting... May 24 09:02:03 volumio sudo[1703]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 24 09:02:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:03 volumio volumio[1072]: info: No need to fix Spotify hosts May 24 09:02:03 volumio go-librespot[1706]: time="2025-05-24T09:02:03+03:00" level=info msg="running go-librespot 0.2.0" May 24 09:02:03 volumio go-librespot[1706]: time="2025-05-24T09:02:03+03:00" level=debug msg="app state loaded" May 24 09:02:03 volumio go-librespot[1706]: time="2025-05-24T09:02:03+03:00" level=info msg="api server listening on 127.0.0.1:9879" May 24 09:02:03 volumio mpd[1664]: May 24 09:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 24 09:02:03 volumio volumio[1072]: info: Volumio called home May 24 09:02:03 volumio sudo[1728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl May 24 09:02:03 volumio sudo[1728]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:03 volumio sudo[1728]: pam_unix(sudo:session): session closed for user root May 24 09:02:03 volumio volumio[1072]: info: Starting Shairport Sync May 24 09:02:04 volumio volumio[1072]: info: Starting Shairport Sync May 24 09:02:04 volumio sudo[1731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:02:04 volumio sudo[1731]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio volumio[1072]: info: Starting Shairport Sync May 24 09:02:04 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 24 09:02:04 volumio systemd[1]: shairport-sync.service: Succeeded. May 24 09:02:04 volumio sudo[1733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:02:04 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 24 09:02:04 volumio sudo[1733]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio sudo[1736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:02:04 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 24 09:02:04 volumio volumio[1072]: info: Starting Shairport Sync May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:04 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:04 volumio sudo[1736]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio systemd[1]: Started Music Player Daemon. May 24 09:02:04 volumio sudo[1638]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio sudo[1647]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile May 24 09:02:04 volumio sudo[1743]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 24 09:02:04 volumio sudo[1731]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio sudo[1743]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 24 09:02:04 volumio systemd[1]: shairport-sync.service: Succeeded. May 24 09:02:04 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 24 09:02:04 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 24 09:02:04 volumio sudo[1733]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio sudo[1736]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio sudo[1747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 24 09:02:04 volumio sudo[1747]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio sudo[1747]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 24 09:02:04 volumio systemd[1]: shairport-sync.service: Succeeded. May 24 09:02:04 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 24 09:02:04 volumio volumio[1072]: info: Completed starting Core Plugins May 24 09:02:04 volumio volumio[1072]: info: ------------------------------------------- May 24 09:02:04 volumio volumio[1072]: info: ----- MyVolumio plugins startup ---- May 24 09:02:04 volumio volumio[1072]: info: ------------------------------------------- May 24 09:02:04 volumio volumio[1072]: info: [MyVolumio PluginManager] Fetching plans data.... May 24 09:02:04 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 24 09:02:04 volumio sudo[1743]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=info msg="zeroconf server listening on port 33635" May 24 09:02:04 volumio volumio[1072]: info: MPD Permissions set May 24 09:02:04 volumio volumio[1072]: info: Shairport-Sync Started May 24 09:02:04 volumio volumio[1072]: Error adding Membership: Error: addMembership EINVAL May 24 09:02:04 volumio volumio[1072]: info: Shairport-Sync Started May 24 09:02:04 volumio volumio[1072]: info: Shairport-Sync Started May 24 09:02:04 volumio volumio[1072]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 24 09:02:04 volumio volumio[1072]: SPOTIFY: BQAI4SqPqICZvKt87DXvddKN9yWKTlNsGq2qe3zugQyYnXZ9JJ8NqijvqPN-Nn8QiKoe7zeRfgrlYZdb1LQMqhcy9Uo5DoiZmmafX3yeerQev_r7Zt6ImGF7H22jS1Z_tCCCr-A8zG3UVlsEhWLUO7lugcQudGpzGsvfJCjNqvFH_zuoSeqw-RCweiJ39j92M1acqxJqU11rF5QwMHOODXyxI2JM_FLTnSShdA6I9TvukUxLfN0PvKCW__fMVxKxxqjeqPpJBuKQRVjFH6YGljh00c8VOC4la3OrUSDss3rOa2g May 24 09:02:04 volumio volumio[1072]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 24 09:02:04 volumio volumio[1072]: info: New Spotify access token = BQAI4SqPqICZvKt87DXvddKN9yWKTlNsGq2qe3zugQyYnXZ9JJ8NqijvqPN-Nn8QiKoe7zeRfgrlYZdb1LQMqhcy9Uo5DoiZmmafX3yeerQev_r7Zt6ImGF7H22jS1Z_tCCCr-A8zG3UVlsEhWLUO7lugcQudGpzGsvfJCjNqvFH_zuoSeqw-RCweiJ39j92M1acqxJqU11rF5QwMHOODXyxI2JM_FLTnSShdA6I9TvukUxLfN0PvKCW__fMVxKxxqjeqPpJBuKQRVjFH6YGljh00c8VOC4la3OrUSDss3rOa2g May 24 09:02:04 volumio volumio[1072]: info: Spotify credentials grant success - running version from March 24, 2019 May 24 09:02:04 volumio volumio[1072]: error: MPD error: The expression evaluated to a falsy value: May 24 09:02:04 volumio volumio[1072]: assert.ok(self.idling) May 24 09:02:04 volumio volumio[1072]: error: The expression evaluated to a falsy value: May 24 09:02:04 volumio volumio[1072]: assert.ok(self.idling) May 24 09:02:04 volumio volumio[1072]: info: MPD running with PID1664 May 24 09:02:04 volumio volumio[1072]: ,establishing connection May 24 09:02:04 volumio volumio[1072]: info: Shairport-Sync Started May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:04 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:04 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="obtained new client token: AADdIyIKx/FvDKMaPptRpY8QCWpWvcezBUPhXJHRzYvd+UmIF0G7UY0B/3eTcWwa5FrgwJPLPycuHZPQctCbdGQUHRP09FPSoGKJGugJ3H9YDbpcfDmdAXLkuCpnfqau/GFOd1XqUYyMvhm3Cutz0YH51BPtHRHkZzvj3LNF5WvTnqdNVsbFW5uER4acEBgWtGsH0E4Oa5DAztxCRh1CQ0JnlTRy5wMJb9D5LZFqIxAX8d8MKEjQ" May 24 09:02:04 volumio volumio[1072]: SPOTIFY: User informations: {"country":"UA","display_name":"Igor","email":"ihhorm@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/pb5pp9zr5gss9vfrrdysusbut"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/pb5pp9zr5gss9vfrrdysusbut","id":"pb5pp9zr5gss9vfrrdysusbut","images":[],"product":"premium","type":"user","uri":"spotify:user:pb5pp9zr5gss9vfrrdysusbut"} May 24 09:02:04 volumio volumio[1072]: info: Spotify Successfully logged in May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 24 09:02:04 volumio volumio[1072]: info: [1748066524365] CoreMusicLibrary::Adding element Spotify May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:04 volumio volumio[1072]: Cannot find translation for source YouTube2 May 24 09:02:04 volumio volumio[1072]: Cannot find translation for source YouTube Music May 24 09:02:04 volumio volumio[1072]: Cannot find translation for source Spotify May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="completed keyexchange" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="completed challenge" May 24 09:02:04 volumio volumio[1072]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 16 May 24 09:02:04 volumio volumio-remote-updater[744]: [2025-05-24 09:02:04] [connect] Successful connection May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=info msg="authenticated AP as pb5pp9zr5gss9vfrrdysusbut" May 24 09:02:04 volumio volumio-remote-updater[744]: [2025-05-24 09:02:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748066524 101 May 24 09:02:04 volumio volumio[1072]: 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: 17 May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 24 09:02:04 volumio sudo[1766]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 24 09:02:04 volumio sudo[1766]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio systemd[1]: Stopping Music Player Daemon... May 24 09:02:04 volumio systemd[1]: mpd.service: Succeeded. May 24 09:02:04 volumio systemd[1]: Stopped Music Player Daemon. May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=info msg="authenticated Login5 as pb5pp9zr5gss9vfrrdysusbut" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="initializing zeroconf session, username: pb5pp9zr5gss9vfrrdysusbut" May 24 09:02:04 volumio systemd[1]: Starting Music Player Daemon... May 24 09:02:04 volumio sudo[1768]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 24 09:02:04 volumio sudo[1768]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:04 volumio sudo[1768]: pam_unix(sudo:session): session closed for user root May 24 09:02:04 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="dealer connection opened" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=trace msg="starting accesspoint recv loop" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=trace msg="received accesspoint ping" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=trace msg="starting dealer recv loop" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="received connection id: YTgwMDVlYjItOTZiZC00OGI3LTliZWEtNzE5ODZjZjk4MDI0K2RlYWxlcit0Y3A6Ly8wYWNhNDBjNi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNjM0Rjc0Mjg2MjdEODYyMzFGQUJENTNCNzM4RjFENTkxQUY0QjE0M0FDQTVBNEYwQzc4OUM1Q0U2ODhGMDgzQw==" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=trace msg="received accesspoint pong ack" May 24 09:02:04 volumio go-librespot[1706]: time="2025-05-24T09:02:04+03:00" level=debug msg="put connect state because NEW_DEVICE" May 24 09:02:05 volumio mpd[1770]: May 24 09:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 24 09:02:05 volumio systemd[1]: Started Music Player Daemon. May 24 09:02:05 volumio sudo[1766]: pam_unix(sudo:session): session closed for user root May 24 09:02:05 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:05 volumio volumio[1072]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 18 May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::volumioGetVisibleSources May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:05 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::volumioGetQueue May 24 09:02:05 volumio volumio[1072]: info: CoreStateMachine::getQueue May 24 09:02:05 volumio volumio[1072]: info: CorePlayQueue::getQueue May 24 09:02:05 volumio volumio[1072]: info: Listing playlists May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 24 09:02:05 volumio volumio[1072]: info: Received Get System Info May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 09:02:05 volumio volumio[1072]: info: Discovery: Getting this device information May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:05 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:05 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 24 09:02:05 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 24 09:02:06 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 24 09:02:06 volumio volumio[1072]: info: Received Get System Info May 24 09:02:06 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 09:02:06 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 09:02:06 volumio volumio[1072]: info: Discovery: Getting this device information May 24 09:02:06 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:06 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:06 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 09:02:06 volumio volumio[1072]: info: go-librespot daemon successfully initialized May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 24 09:02:07 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.0.252 from 192.168.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 19 May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::volumioGetVisibleSources May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:07 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:07 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::volumioGetQueue May 24 09:02:07 volumio volumio[1072]: info: CoreStateMachine::getQueue May 24 09:02:07 volumio volumio[1072]: info: CorePlayQueue::getQueue May 24 09:02:07 volumio volumio[1072]: info: Listing playlists May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 24 09:02:07 volumio volumio[1072]: info: Received Get System Info May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 09:02:07 volumio volumio[1072]: info: Discovery: Getting this device information May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:07 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 09:02:07 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:07 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:08 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 24 09:02:08 volumio volumio[1072]: info: Received Get System Info May 24 09:02:08 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 09:02:08 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 09:02:08 volumio volumio[1072]: info: Discovery: Getting this device information May 24 09:02:08 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:08 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:08 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 09:02:08 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 24 09:02:08 volumio sudo[1968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 24 09:02:08 volumio sudo[1968]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:08 volumio sudo[1968]: pam_unix(sudo:session): session closed for user root May 24 09:02:08 volumio sudo[1971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 24 09:02:08 volumio sudo[1971]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:08 volumio sudo[1971]: pam_unix(sudo:session): session closed for user root May 24 09:02:08 volumio sudo[1974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 24 09:02:08 volumio sudo[1974]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:08 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 24 09:02:08 volumio sudo[1974]: pam_unix(sudo:session): session closed for user root May 24 09:02:08 volumio volumio[1072]: info: Upmpdcli Daemon Started May 24 09:02:09 volumio volumio[1976]: Generating RSA private key, 4096 bit long modulus (2 primes) May 24 09:02:09 volumio volumio[1976]: ............................++++ May 24 09:02:09 volumio volumio[1072]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 24 09:02:10 volumio volumio[1072]: Cannot compose Albumart path May 24 09:02:10 volumio volumio[1976]: ......................................................................................................++++ May 24 09:02:10 volumio volumio[1976]: e is 65537 (0x010001) May 24 09:02:10 volumio volumio[1976]: writing RSA key May 24 09:02:10 volumio volumio[1072]: Cannot compose Albumart path May 24 09:02:10 volumio volumio[1072]: Cannot compose Albumart path May 24 09:02:10 volumio volumio[1072]: Cannot compose Albumart path May 24 09:02:10 volumio volumio[1072]: Cannot compose Albumart path May 24 09:02:10 volumio volumio[1072]: Cannot compose Albumart path May 24 09:02:10 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket May 24 09:02:10 volumio go-librespot[1706]: time="2025-05-24T09:02:10+03:00" level=debug msg="new websocket client" May 24 09:02:10 volumio volumio[1072]: info: Connection to go-librespot Websocket established May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 24 09:02:13 volumio volumio[1072]: info: Adding plugin bluetooth to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: Adding plugin multiroom to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: Adding plugin metavolumio to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: Adding plugin cd_controller to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: Adding plugin qobuzconnect to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: Adding plugin smart_inputs to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: Adding plugin tidalconnect to MyMusic Plugins May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 24 09:02:13 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:13 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:13 volumio volumio[1072]: info: Starting MyVolumio Remote Streaming Endpoints May 24 09:02:13 volumio volumio[1072]: info: MyVolumio login type: Token May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 24 09:02:13 volumio volumio[1072]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 24 09:02:14 volumio volumio[1072]: info: Starting Streaming Service Transparent Proxy May 24 09:02:14 volumio volumio[1072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 24 09:02:14 volumio volumio[1072]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 24 09:02:14 volumio volumio[1072]: info: Streaming services startup May 24 09:02:14 volumio volumio[1072]: info: Starting Streaming Daemon May 24 09:02:14 volumio sudo[2038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 24 09:02:14 volumio sudo[2038]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:14 volumio sudo[2038]: pam_unix(sudo:session): session closed for user root May 24 09:02:14 volumio volumio[1072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 24 09:02:14 volumio volumio[1072]: info: Getting Spotify volume May 24 09:02:14 volumio volumio[1072]: error: Cannot start Volumio Streaming Daemon May 24 09:02:14 volumio volumio[1072]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 24 09:02:14 volumio volumio[1072]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 24 09:02:14 volumio volumio[1072]: info: Spotify volume: 100 May 24 09:02:14 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 May 24 09:02:14 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:14 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:14 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:14 volumio volumio[1072]: STREAMING PROXY: Starting server on port 3245 May 24 09:02:14 volumio volumio[1072]: Node JS runtime: 14 May 24 09:02:14 volumio volumio[1072]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 24 09:02:15 volumio volumio[1072]: info: MyVolumio token set successfully May 24 09:02:15 volumio volumio[1072]: info: MYVOLUMIO: Adding device May 24 09:02:15 volumio volumio[1072]: info: MYVOLUMIO: Evaluating Server May 24 09:02:15 volumio volumio[1072]: info: MyVolumio status changed May 24 09:02:15 volumio volumio[1072]: info: Streaming services startup May 24 09:02:15 volumio volumio[1072]: info: Starting Streaming Daemon May 24 09:02:15 volumio volumio[1072]: info: Removing browser output: myVolumio user plan is not superstar May 24 09:02:15 volumio volumio[1072]: info: Removing audio output: May 24 09:02:15 volumio volumio[1072]: info: Stoppping Tunnel 1 May 24 09:02:15 volumio sudo[2062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 24 09:02:15 volumio sudo[2062]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:15 volumio sudo[2062]: pam_unix(sudo:session): session closed for user root May 24 09:02:15 volumio volumio[1072]: error: Cannot start Volumio Streaming Daemon May 24 09:02:15 volumio sudo[2065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 24 09:02:15 volumio volumio[1072]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 24 09:02:15 volumio volumio[1072]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 24 09:02:15 volumio sudo[2065]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 09:02:15 volumio sudo[2065]: pam_unix(sudo:session): session closed for user root May 24 09:02:15 volumio volumio[1072]: info: Remote SSH Stopped May 24 09:02:15 volumio volumio[1072]: info: Setting Geolocation for MyVolumio to eu6 May 24 09:02:15 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:15 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:15 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:16 volumio volumio[1072]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 24 09:02:16 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 24 09:02:16 volumio volumio[1072]: info: Updating MyVolumio device info May 24 09:02:16 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:17 volumio volumio[1072]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 24 09:02:20 volumio volumio[1072]: info: MYVOLUMIO: Adding device May 24 09:02:20 volumio volumio[1072]: info: MYVOLUMIO: Evaluating Server May 24 09:02:21 volumio systemd[1]: systemd-fsckd.service: Succeeded. May 24 09:02:22 volumio systemd[1]: systemd-hostnamed.service: Succeeded. May 24 09:02:22 volumio volumio[1072]: error: Failed to ping endpoint eu9.myvolumio.org : unknown error May 24 09:02:22 volumio volumio[1072]: info: Setting Geolocation for MyVolumio to eu6 May 24 09:02:22 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:22 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:22 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:23 volumio volumio[1072]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 24 09:02:23 volumio volumio[1072]: info: Updating MyVolumio device info May 24 09:02:23 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:23 volumio volumio[1072]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 24 09:02:24 volumio volumio[1072]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 24 09:02:24 volumio volumio[1072]: info: Received Get System Version May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:02:24 volumio volumio[1072]: info: Received Get System Info May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 09:02:24 volumio volumio[1072]: info: Discovery: Getting this device information May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:24 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:24 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 09:02:28 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 24 09:02:28 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 May 24 09:02:28 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:28 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:31 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:31 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:31 volumio systemd[1]: systemd-timedated.service: Succeeded. May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::volumioGetBrowseSources May 24 09:02:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:02:34 volumio volumio[1072]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 24 09:02:34 volumio volumio[1072]: info: Completed starting MyVolumio Plugin May 24 09:02:34 volumio volumio[1072]: [Metrics] CommandRouter: 36s 519.90ms May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::volumiosetStartupVolume May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 24 09:02:34 volumio volumio[1072]: info: VolumeController:: Setting startup Volume 100 May 24 09:02:34 volumio volumio[1072]: info: VolumeController::SetAlsaVolume100 May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::Close All Modals sent May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::Close All Modals sent May 24 09:02:34 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:34 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:34 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 09:02:34 volumio volumio-remote-updater[744]: No test mode May 24 09:02:34 volumio volumio-remote-updater[744]: No alpha test mode May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 24 09:02:34 volumio volumio[1072]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Various Fixes for QOBUZ Connect
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Qobuz Connect Ready
    • \n
\n","title":"Update v3.812","updateavailable":true} May 24 09:02:34 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 24 09:02:35 volumio volumio[1072]: info: Preload queue cleared May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::volumioReplaceandPlayItems May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::ClearQueue May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::clearPlayQueue May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::addQueueItems May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::addQueueItems May 24 09:02:35 volumio volumio[1072]: info: Preload queue cleared May 24 09:02:35 volumio volumio[1072]: info: Adding Item to queue: https://online.radiorelax.ua/RadioRelax_HD May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::volumioPlay May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::play index 0 May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:35 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:35 volumio volumio[1072]: info: [1748066555268] ControllerWebradio::clearAddPlayTrack May 24 09:02:35 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:35 volumio volumio[1072]: info: sendMpdCommand stop took 2 milliseconds May 24 09:02:35 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:35 volumio volumio[1072]: info: May 24 09:02:35 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:35 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:35 volumio volumio[1072]: info: sendMpdCommand clear took 1 milliseconds May 24 09:02:35 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:35 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:35 volumio volumio[1072]: info: ------------------------------ 2ms May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 24 09:02:35 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 24 09:02:35 volumio go-librespot[1706]: time="2025-05-24T09:02:35+03:00" level=trace msg="sent dealer ping" May 24 09:02:35 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:35 volumio volumio[1072]: info: May 24 09:02:35 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:35 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:35 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 0 milliseconds May 24 09:02:35 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:35 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:35 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:35 volumio volumio[1072]: info: sendMpdCommand play took 1 milliseconds May 24 09:02:35 volumio go-librespot[1706]: time="2025-05-24T09:02:35+03:00" level=trace msg="received dealer pong" May 24 09:02:36 volumio volumio[1072]: info: May 24 09:02:36 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:36 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:36 volumio volumio[1072]: info: sendMpdCommand status took 20 milliseconds May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:36 volumio volumio[1072]: info: May 24 09:02:36 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:36 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:36 volumio volumio[1072]: info: May 24 09:02:36 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:36 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:36 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:36 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:36 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:36 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:36 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:36 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:36 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:36 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:36 volumio volumio[1072]: info: ------------------------------ 25ms May 24 09:02:36 volumio volumio[1072]: info: ------------------------------ 3ms May 24 09:02:36 volumio volumio[1072]: info: sendMpdCommand status took 3 milliseconds May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:36 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:36 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:36 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:36 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:36 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:36 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":721,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:36 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:36 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:36 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:36 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:36 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:36 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:36 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:36 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:36 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:36 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:36 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:36 volumio volumio[1072]: info: ------------------------------ 12ms May 24 09:02:36 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:36 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:37 volumio volumio[1072]: info: Preload queue cleared May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::volumioReplaceandPlayItems May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::ClearQueue May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::stPlaybackTimer May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::serviceStop May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::serviceStop May 24 09:02:37 volumio volumio[1072]: info: [1748066557268] ControllerWebradio::stop May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::clearPlayQueue May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::addQueueItems May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::addQueueItems May 24 09:02:37 volumio volumio[1072]: info: Preload queue cleared May 24 09:02:37 volumio volumio[1072]: info: Adding Item to queue: https://online.radiorelax.ua/RadioRelax_HD May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:02:37 volumio volumio[1072]: info: CoreCommandRouter::volumioPlay May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::play index 0 May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:37 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:37 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:37 volumio volumio[1072]: info: [1748066557278] ControllerWebradio::clearAddPlayTrack May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:37 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:37 volumio volumio[1072]: info: May 24 09:02:37 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:37 volumio volumio[1072]: info: sendMpdCommand stop took 350 milliseconds May 24 09:02:37 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:37 volumio volumio[1072]: info: sendMpdCommand stop took 340 milliseconds May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:37 volumio volumio[1072]: info: May 24 09:02:37 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:37 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:37 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:37 volumio volumio[1072]: info: sendMpdCommand clear took 0 milliseconds May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:37 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:37 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:37 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:37 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:37 volumio volumio[1072]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 24 09:02:37 volumio volumio[1072]: info: ------------------------------ 3ms May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:38 volumio volumio[1072]: info: May 24 09:02:38 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:38 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 0 milliseconds May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:38 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand play took 1 milliseconds May 24 09:02:38 volumio volumio[1072]: info: May 24 09:02:38 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:38 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:38 volumio volumio[1072]: info: May 24 09:02:38 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:38 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:38 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:38 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:38 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:38 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:38 volumio volumio[1072]: info: ------------------------------ 4ms May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:38 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:38 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:38 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:38 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:38 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:38 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:38 volumio volumio[1072]: info: ------------------------------ 13ms May 24 09:02:38 volumio volumio[1072]: info: May 24 09:02:38 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:38 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:38 volumio volumio[1072]: info: May 24 09:02:38 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:38 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:38 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:38 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:38 volumio volumio[1072]: info: ------------------------------ 6ms May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand status took 5 milliseconds May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:38 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:38 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:38 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:38 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:38 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":721,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:38 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:38 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:38 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:38 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:38 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:38 volumio volumio[1072]: info: ------------------------------ 14ms May 24 09:02:38 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:38 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:39 volumio volumio[1072]: info: May 24 09:02:39 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:39 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:39 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:39 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:39 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:39 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:39 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:39 volumio volumio[1072]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 24 09:02:39 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::syncState stateService stop May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:39 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:39 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:39 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:39 volumio volumio[1072]: info: [1748066559932] ControllerWebradio::clearAddPlayTrack May 24 09:02:39 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:39 volumio volumio[1072]: info: ------------------------------ 8ms May 24 09:02:39 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:39 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:39 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:39 volumio volumio[1072]: info: sendMpdCommand stop took 9 milliseconds May 24 09:02:39 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:39 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:39 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:39 volumio volumio[1072]: info: May 24 09:02:39 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:39 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:39 volumio volumio[1072]: info: sendMpdCommand clear took 8 milliseconds May 24 09:02:39 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:39 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:39 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:40 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 0 milliseconds May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand play took 0 milliseconds May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:40 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 3ms May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:40 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:40 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 13ms May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:40 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:40 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:40 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:40 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:40 volumio volumio[1072]: info: May 24 09:02:40 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 5ms May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand status took 4 milliseconds May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 2ms May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":723,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:40 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:40 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 15ms May 24 09:02:40 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 10 milliseconds May 24 09:02:40 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:40 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":723,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:40 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:40 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:40 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:40 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:40 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:40 volumio volumio[1072]: info: ------------------------------ 24ms May 24 09:02:40 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:41 volumio volumio[1072]: info: BOOT COMPLETED May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 24 09:02:42 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState stateService stop May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: [1748066562159] ControllerWebradio::clearAddPlayTrack May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 11ms May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand stop took 7 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:42 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand clear took 8 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:42 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:42 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 1 milliseconds May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand play took 1 milliseconds May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:42 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 4ms May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:42 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:42 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 12ms May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:42 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:42 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:42 volumio volumio[1072]: info: May 24 09:02:42 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 6ms May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand status took 5 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 2ms May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":729,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:42 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:42 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 14ms May 24 09:02:42 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 8 milliseconds May 24 09:02:42 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:42 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":729,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:42 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:42 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:42 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:42 volumio volumio[1072]: info: ------------------------------ 22ms May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:44 volumio volumio[1072]: info: May 24 09:02:44 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:44 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:44 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:44 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:44 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:44 volumio volumio[1072]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 24 09:02:44 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::syncState stateService stop May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:44 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:44 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:44 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:44 volumio volumio[1072]: info: [1748066564463] ControllerWebradio::clearAddPlayTrack May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:44 volumio volumio[1072]: info: ------------------------------ 11ms May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:44 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:44 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:44 volumio volumio[1072]: info: sendMpdCommand stop took 9 milliseconds May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:44 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:44 volumio volumio[1072]: info: May 24 09:02:44 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:44 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:44 volumio volumio[1072]: info: sendMpdCommand clear took 13 milliseconds May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:44 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:44 volumio volumio[1072]: info: ------------------------------ 327ms May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:44 volumio volumio[1072]: info: May 24 09:02:44 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:44 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:44 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 1 milliseconds May 24 09:02:44 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:44 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:44 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:44 volumio volumio[1072]: info: sendMpdCommand play took 1 milliseconds May 24 09:02:45 volumio volumio[1072]: info: May 24 09:02:45 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:45 volumio volumio[1072]: info: May 24 09:02:45 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand status took 3 milliseconds May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:45 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:45 volumio volumio[1072]: info: ------------------------------ 6ms May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:45 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:45 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:45 volumio volumio[1072]: info: ------------------------------ 12ms May 24 09:02:45 volumio volumio[1072]: info: May 24 09:02:45 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:45 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:45 volumio volumio[1072]: info: May 24 09:02:45 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:45 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:45 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:45 volumio volumio[1072]: info: May 24 09:02:45 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:45 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:45 volumio volumio[1072]: info: May 24 09:02:45 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:45 volumio volumio[1072]: info: ------------------------------ 6ms May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand status took 5 milliseconds May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:45 volumio volumio[1072]: info: ------------------------------ 2ms May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand status took 2 milliseconds May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":721,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:45 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:45 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:45 volumio volumio[1072]: info: ------------------------------ 16ms May 24 09:02:45 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 8 milliseconds May 24 09:02:45 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:45 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":721,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:45 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:45 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:45 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:45 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:45 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:45 volumio volumio[1072]: info: ------------------------------ 22ms May 24 09:02:45 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:46 volumio volumio[1072]: info: May 24 09:02:46 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:46 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:46 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:46 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:46 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:46 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:46 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:46 volumio volumio[1072]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 24 09:02:46 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::syncState stateService stop May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:46 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:46 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:46 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:46 volumio volumio[1072]: info: [1748066566767] ControllerWebradio::clearAddPlayTrack May 24 09:02:46 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:46 volumio volumio[1072]: info: ------------------------------ 16ms May 24 09:02:46 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:46 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:46 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:46 volumio volumio[1072]: info: sendMpdCommand stop took 5 milliseconds May 24 09:02:46 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:46 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:46 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:46 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:46 volumio volumio[1072]: info: May 24 09:02:46 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:46 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:46 volumio volumio[1072]: info: sendMpdCommand clear took 6 milliseconds May 24 09:02:46 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:46 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:46 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:47 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 0 milliseconds May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand play took 0 milliseconds May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand status took 3 milliseconds May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:47 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 6ms May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:47 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:47 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 15ms May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:47 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:47 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:47 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:47 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:47 volumio volumio[1072]: info: May 24 09:02:47 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 5ms May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand status took 5 milliseconds May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 2ms May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":727,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:47 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:47 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 14ms May 24 09:02:47 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 8 milliseconds May 24 09:02:47 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:47 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":727,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"RadioRelax_HD","artist":"Radio Relax","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:47 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:47 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:47 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:47 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:47 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:47 volumio volumio[1072]: info: ------------------------------ 19ms May 24 09:02:47 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:47 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:48 volumio volumio[1072]: info: May 24 09:02:48 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:48 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:48 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:48 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:48 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:48 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:48 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:48 volumio volumio[1072]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 24 09:02:48 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::syncState stateService stop May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:48 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:48 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:48 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:48 volumio volumio[1072]: info: [1748066568960] ControllerWebradio::clearAddPlayTrack May 24 09:02:48 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:48 volumio volumio[1072]: info: ------------------------------ 13ms May 24 09:02:48 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:48 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:48 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:48 volumio volumio[1072]: info: sendMpdCommand stop took 7 milliseconds May 24 09:02:48 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:48 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:48 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:48 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:48 volumio volumio[1072]: info: May 24 09:02:48 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:48 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:48 volumio volumio[1072]: info: sendMpdCommand clear took 5 milliseconds May 24 09:02:48 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:48 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:48 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:49 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_HD" took 0 milliseconds May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand play took 1 milliseconds May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand status took 2 milliseconds May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand status took 1 milliseconds May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:49 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 5ms May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_HD","trackType":""} May 24 09:02:49 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:49 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 12ms May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:49 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:49 volumio volumio[1072]: info: Preload queue cleared May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioReplaceandPlayItems May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::ClearQueue May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::stPlaybackTimer May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::serviceStop May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::serviceStop May 24 09:02:49 volumio volumio[1072]: info: [1748066569642] ControllerWebradio::stop May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::clearPlayQueue May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::addQueueItems May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::addQueueItems May 24 09:02:49 volumio volumio[1072]: info: Preload queue cleared May 24 09:02:49 volumio volumio[1072]: info: Adding Item to queue: https://online.radiorelax.ua/RadioRelax_Ukr_HD May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::volumioPlay May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::play index 0 May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: info: [1748066569652] ControllerWebradio::clearAddPlayTrack May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:02:49 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:49 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:49 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:49 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 26ms May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand status took 25 milliseconds May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand stop took 16 milliseconds May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand stop took 6 milliseconds May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand clear May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:49 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 5ms May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand status took 4 milliseconds May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand status took 5 milliseconds May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 4 milliseconds May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand clear took 4 milliseconds May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand load "https://online.radiorelax.ua/RadioRelax_Ukr_HD" May 24 09:02:49 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:49 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:49 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:49 volumio volumio[1072]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 34ms May 24 09:02:49 volumio volumio[1072]: error: updateQueue error: null May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 4ms May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 4 milliseconds May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 4 milliseconds May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:49 volumio volumio[1072]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 24 09:02:49 volumio volumio[1072]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 11ms May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 11ms May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_Ukr_HD" May 24 09:02:49 volumio volumio[1072]: info: May 24 09:02:49 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:49 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand add "https://online.radiorelax.ua/RadioRelax_Ukr_HD" took 1 milliseconds May 24 09:02:49 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:02:49 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand play May 24 09:02:49 volumio volumio[1072]: info: ------------------------------ 1ms May 24 09:02:49 volumio volumio[1072]: info: sendMpdCommand play took 0 milliseconds May 24 09:02:50 volumio volumio[1072]: info: May 24 09:02:50 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:50 volumio volumio[1072]: info: May 24 09:02:50 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand status took 3 milliseconds May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand status took 0 milliseconds May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 0 milliseconds May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:50 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:50 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_Ukr_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_Ukr_HD","trackType":""} May 24 09:02:50 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus stop May 24 09:02:50 volumio volumio[1072]: info: ------------------------------ 6ms May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:50 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:50 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RadioRelax_Ukr_HD","artist":null,"album":null,"uri":"https://online.radiorelax.ua/RadioRelax_Ukr_HD","trackType":""} May 24 09:02:50 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:50 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:50 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:50 volumio volumio[1072]: info: ------------------------------ 15ms May 24 09:02:50 volumio volumio[1072]: info: May 24 09:02:50 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:50 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:50 volumio volumio[1072]: info: May 24 09:02:50 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:50 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:50 volumio volumio[1072]: info: May 24 09:02:50 volumio volumio[1072]: ---------------------------- MPD announces system playlist update May 24 09:02:50 volumio volumio[1072]: info: Ignoring MPD Status Update May 24 09:02:50 volumio volumio[1072]: info: May 24 09:02:50 volumio volumio[1072]: ---------------------------- MPD announces state update: player May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::getState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand status May 24 09:02:50 volumio volumio[1072]: info: ------------------------------ 5ms May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand status took 5 milliseconds May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:50 volumio volumio[1072]: info: ------------------------------ 2ms May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand status took 2 milliseconds May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseState May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:50 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:50 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":721,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"YAKTAK x NICHKA - Тихо плакала","artist":"Radio Relax Ukrainian","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_Ukr_HD","trackType":""} May 24 09:02:50 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:50 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:50 volumio volumio[1072]: info: ------------------------------ 20ms May 24 09:02:50 volumio volumio[1072]: info: sendMpdCommand playlistinfo took 15 milliseconds May 24 09:02:50 volumio volumio[1072]: verbose: ControllerMpd::parseTrackInfo May 24 09:02:50 volumio volumio[1072]: info: ControllerMpd::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::servicePushState May 24 09:02:50 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:02:50 volumio volumio[1072]: verbose: STATE SERVICE {"status":"play","position":0,"seek":721,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"YAKTAK x NICHKA - Тихо плакала","artist":"Radio Relax Ukrainian","album":null,"uri":"https://online.radiorelax.ua/RadioRelax_Ukr_HD","trackType":""} May 24 09:02:50 volumio volumio[1072]: verbose: CURRENT POSITION 0 May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState stateService play May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::syncState currentStatus play May 24 09:02:50 volumio volumio[1072]: info: Received an update from plugin. extracting info from payload May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:50 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:02:50 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:02:50 volumio volumio[1072]: info: ------------------------------ 29ms May 24 09:02:50 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:50 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:50 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:50 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:02:53 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:02:54 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 8 May 24 09:02:54 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState May 24 09:03:03 volumio volumio[1072]: info: Preload queue cleared May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::volumioReplaceandPlayItems May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::ClearQueue May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::stPlaybackTimer May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::pushState May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::serviceStop May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::serviceStop May 24 09:03:03 volumio volumio[1072]: info: [1748066583795] ControllerWebradio::stop May 24 09:03:03 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::clearPlayQueue May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::addQueueItems May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::addQueueItems May 24 09:03:03 volumio volumio[1072]: info: Preload queue cleared May 24 09:03:03 volumio volumio[1072]: info: Adding Item to queue: https://online.radiorelax.ua/RadioRelax_Int_HD May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPushQueue May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::saveQueue May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::updateTrackBlock May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::getTrackBlock May 24 09:03:03 volumio volumio[1072]: info: CoreCommandRouter::volumioPlay May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::play index 0 May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::stop May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::play index undefined May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:03:03 volumio volumio[1072]: info: CoreStateMachine::startPlaybackTimer May 24 09:03:03 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 May 24 09:03:03 volumio volumio[1072]: info: [1748066583807] ControllerWebradio::clearAddPlayTrack May 24 09:03:03 volumio volumio[1072]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:03:03 volumio volumio[1072]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 09:03:03 volumio volumio[1072]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' May 24 09:03:03 volumio volumio[1072]: at Object.readdirSync (fs.js:1048:3) May 24 09:03:03 volumio volumio[1072]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) May 24 09:03:03 volumio volumio[1072]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) May 24 09:03:03 volumio volumio[1072]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) May 24 09:03:03 volumio volumio[1072]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) May 24 09:03:03 volumio volumio[1072]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) May 24 09:03:03 volumio volumio[1072]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) May 24 09:03:03 volumio volumio[1072]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) May 24 09:03:03 volumio volumio[1072]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) May 24 09:03:03 volumio volumio[1072]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) May 24 09:03:03 volumio volumio[1072]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) May 24 09:03:03 volumio volumio[1072]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) May 24 09:03:03 volumio volumio[1072]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) May 24 09:03:03 volumio volumio[1072]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) May 24 09:03:03 volumio volumio[1072]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) May 24 09:03:03 volumio volumio[1072]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { May 24 09:03:03 volumio volumio[1072]: errno: -20, May 24 09:03:03 volumio volumio[1072]: syscall: 'scandir', May 24 09:03:03 volumio volumio[1072]: code: 'ENOTDIR', May 24 09:03:03 volumio volumio[1072]: path: '/tmp/peppyrunning' May 24 09:03:03 volumio volumio[1072]: } May 24 09:03:03 volumio volumio[1072]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 09:03:03 volumio sudo[2369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-24 09:02 May 24 09:03:03 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 12:21:23 PM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="a9588e47e4b05f1a05bf70b4acc7555c"