-- Logs begin at Fri 2026-10-16 19:54:46 UTC, end at Fri 2026-10-16 19:56:35 UTC. -- Oct 16 19:55:00 volumio wireless.js[776]: trying... Oct 16 19:55:00 volumio sudo[958]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 16 19:55:00 volumio sudo[958]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:00 volumio sudo[958]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:01 volumio wireless.js[776]: trying... Oct 16 19:55:01 volumio sudo[967]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 16 19:55:01 volumio sudo[967]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:01 volumio sudo[967]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:02 volumio wpa_supplicant[919]: wlan0: Associated with 70:4d:7b:d7:30:2c Oct 16 19:55:02 volumio wpa_supplicant[919]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=FR Oct 16 19:55:02 volumio wpa_supplicant[919]: wlan0: WPA: Key negotiation completed with 70:4d:7b:d7:30:2c [PTK=CCMP GTK=CCMP] Oct 16 19:55:02 volumio wpa_supplicant[919]: wlan0: CTRL-EVENT-CONNECTED - Connection to 70:4d:7b:d7:30:2c completed [id=0 id_str=] Oct 16 19:55:02 volumio dhcpcd[897]: wlan0: carrier acquired Oct 16 19:55:02 volumio wireless.js[776]: trying... Oct 16 19:55:02 volumio dhcpcd[897]: wlan0: rebinding lease of 192.168.1.145 Oct 16 19:55:02 volumio sudo[988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 16 19:55:02 volumio sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:02 volumio sudo[988]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:02 volumio dhcpcd[897]: wlan0: leased 192.168.1.145 for 86400 seconds Oct 16 19:55:02 volumio avahi-daemon[651]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.145. Oct 16 19:55:02 volumio avahi-daemon[651]: New relevant interface wlan0.IPv4 for mDNS. Oct 16 19:55:02 volumio avahi-daemon[651]: Registering new address record for 192.168.1.145 on wlan0.IPv4. Oct 16 19:55:02 volumio dhcpcd[897]: wlan0: adding host route to 192.168.1.145 via 127.0.0.1 Oct 16 19:55:02 volumio dhcpcd[897]: wlan0: adding route to 192.168.1.0/24 Oct 16 19:55:02 volumio dhcpcd[897]: wlan0: adding default route via 192.168.1.1 Oct 16 19:55:02 volumio dhcpcd[897]: forked to background, child pid 1017 Oct 16 19:55:02 volumio sudo[893]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:03 volumio wireless.js[776]: trying... Oct 16 19:55:03 volumio sudo[1022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 16 19:55:03 volumio sudo[1022]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:03 volumio sudo[1022]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:03 volumio wireless.js[776]: Connected to: ----ASUS_5G Oct 16 19:55:03 volumio wireless.js[776]: ---- Oct 16 19:55:03 volumio sudo[1031]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 19:55:03 volumio sudo[1031]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:03 volumio sudo[1031]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:03 volumio wireless.js[776]: ... joined AP, wlan0 IPv4 is 192.168.1.145, ipV6 is undefined Oct 16 19:55:03 volumio wireless.js[776]: It's done! AP Oct 16 19:55:03 volumio systemd[1]: Started Wireless Services. Oct 16 19:55:03 volumio systemd[1]: Starting Volumio Backend Module... Oct 16 19:55:03 volumio systemd[1]: Started Volumio Backend Module. Oct 16 19:55:03 volumio systemd[1]: Starting Volumio Streaming Daemon... Oct 16 19:55:03 volumio systemd[1]: Started Volumio Streaming Daemon. Oct 16 19:55:03 volumio systemd[1]: Starting Multi-User System. Oct 16 19:55:03 volumio systemd[1]: Reached target Multi-User System. Oct 16 19:55:03 volumio systemd[1]: Starting Graphical Interface. Oct 16 19:55:03 volumio systemd[1]: Reached target Graphical Interface. Oct 16 19:55:03 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 16 19:55:03 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 16 19:55:03 volumio systemd[1]: Startup finished in 9.197s (kernel) + 18.666s (userspace) = 27.864s. Oct 16 19:55:04 volumio ntpd[733]: Listen normally on 3 wlan0 192.168.1.145 UDP 123 Oct 16 19:55:04 volumio ntpd[733]: peers refreshed Oct 16 19:55:04 volumio volumio-streaming-daemon[1041]: ############################ Oct 16 19:55:04 volumio volumio-streaming-daemon[1041]: # Volumio Streaming Daemon # Oct 16 19:55:04 volumio volumio-streaming-daemon[1041]: # Running on port 7777 # Oct 16 19:55:04 volumio volumio-streaming-daemon[1041]: ############################ Oct 16 19:55:04 volumio volumio-streaming-daemon[1041]: Environment: production Oct 16 19:55:04 volumio volumio-remote-updater[600]: [2026-10-16 19:55:04] [info] asio async_connect error: system:111 (Connection refused) Oct 16 19:55:04 volumio volumio-remote-updater[600]: [2026-10-16 19:55:04] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 16 19:55:04 volumio volumio-remote-updater[600]: [2026-10-16 19:55:04] [error] handle_connect error: Underlying Transport Error Oct 16 19:55:06 volumio ntpd_intres[805]: DNS 0.debian.pool.ntp.org -> 195.112.113.253 Oct 16 19:55:06 volumio ntpd_intres[805]: DNS 1.debian.pool.ntp.org -> 162.159.200.123 Oct 16 19:55:06 volumio ntpd_intres[805]: DNS 2.debian.pool.ntp.org -> 213.108.170.26 Oct 16 19:55:06 volumio ntpd_intres[805]: DNS 3.debian.pool.ntp.org -> 195.90.182.235 Oct 16 19:55:06 volumio nmbd[856]: [2026/10/16 19:55:06.337343, 0] ../lib/util/become_daemon.c:124(daemon_ready) Oct 16 19:55:06 volumio nmbd[856]: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Oct 16 19:55:06 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:06 volumio volumio[1040]: info: ----- Volumio2 ---- Oct 16 19:55:06 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:06 volumio volumio[1040]: info: ----- System startup ---- Oct 16 19:55:06 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:06 volumio volumio[1040]: info: MYVOLUMIO Environment detected Oct 16 19:55:07 volumio volumio[1040]: info: Plugin folders cleanup Oct 16 19:55:07 volumio volumio[1040]: info: Scanning into folder /volumio/app/plugins/ Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category audio_interface Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category miscellanea Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category music_service Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category plugins.json Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category system_controller Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category user_interface Oct 16 19:55:07 volumio volumio[1040]: info: Scanning into folder /data/plugins/ Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category accessory Oct 16 19:55:07 volumio volumio[1040]: info: Scanning category miscellanea Oct 16 19:55:07 volumio volumio[1040]: info: Plugin folders cleanup completed Oct 16 19:55:07 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:07 volumio volumio[1040]: info: ----- Core plugins startup ---- Oct 16 19:55:07 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:07 volumio volumio[1040]: info: Loading plugins from folder /volumio/app/plugins/ Oct 16 19:55:07 volumio volumio[1040]: info: Adding plugin upnp to MyMusic Plugins Oct 16 19:55:07 volumio volumio[1040]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 16 19:55:07 volumio volumio[1040]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 16 19:55:07 volumio volumio[1040]: info: Loading plugins from folder /data/plugins/ Oct 16 19:55:07 volumio volumio[1040]: info: Loading plugin "system"... Oct 16 19:55:07 volumio volumio[1040]: info: Loading plugin "appearance"... Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "network"... Oct 16 19:55:09 volumio volumio[1040]: info: Refreshing Cached IP Addresses Oct 16 19:55:09 volumio sudo[1067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "services"... Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "alsa_controller"... Oct 16 19:55:09 volumio sudo[1067]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:09 volumio sudo[1067]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:09 volumio sudo[1069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 19:55:09 volumio sudo[1069]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:09 volumio sudo[1069]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "wizard"... Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "volumio_command_line_client"... Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "upnp"... Oct 16 19:55:09 volumio volumio[1040]: info: [1792180509358] Starting Upmpd Daemon Oct 16 19:55:09 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "my_music"... Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "mpd"... Oct 16 19:55:09 volumio volumio[1040]: info: Loading plugin "upnp_browser"... Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "networkfs"... Oct 16 19:55:10 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "alarm-clock"... Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "airplay_emulation"... Oct 16 19:55:10 volumio volumio[1040]: info: Starting Shairport Sync Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "last_100"... Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "webradio"... Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "i2s_dacs"... Oct 16 19:55:10 volumio volumio[1040]: info: I2S DAC not set, start Auto-detection Oct 16 19:55:10 volumio volumio[1040]: info: Loading plugin "volumiodiscovery"... Oct 16 19:55:11 volumio volumio[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 19:55:11 volumio node[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 19:55:11 volumio node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 19:55:11 volumio node[1040]: *** WARNING *** For more information see Oct 16 19:55:11 volumio node[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 19:55:11 volumio node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 19:55:11 volumio node[1040]: *** WARNING *** For more information see Oct 16 19:55:11 volumio volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 19:55:11 volumio volumio[1040]: *** WARNING *** For more information see Oct 16 19:55:11 volumio volumio[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 19:55:11 volumio volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 19:55:11 volumio volumio[1040]: *** WARNING *** For more information see Oct 16 19:55:11 volumio volumio[1040]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 16 19:55:11 volumio volumio[1040]: Discovery: StartAdv! undefined Oct 16 19:55:11 volumio volumio[1040]: Discovery: Started advertising... Volumio - undefined Oct 16 19:55:11 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "auto_play"... Oct 16 19:55:11 volumio volumio[1040]: info: ControllerAutoPlay - connecting mpd on host: localhost; port: 6600 Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "autostart"... Oct 16 19:55:11 volumio volumio[1040]: info: Applying required configuration parameters for plugin autostart Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "outputs"... Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "albumart"... Oct 16 19:55:11 volumio volumio[1040]: info: Plugin example_plugin is not enabled Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "inputs"... Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "updater_comm"... Oct 16 19:55:11 volumio volumio[1040]: info: Plugin mpdemulation is not enabled Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "rest_api"... Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "websocket"... Oct 16 19:55:11 volumio volumio[1040]: info: Loading plugin "ir_controller"... Oct 16 19:55:11 volumio volumio[1040]: Forking 3 albumart workers Oct 16 19:55:11 volumio volumio[1040]: info: Applying required configuration parameters for plugin ir_controller Oct 16 19:55:12 volumio volumio[1040]: info: ___________ START PLUGINS ___________ Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 19:55:12 volumio volumio[1040]: info: [1792180512226] CoreMusicLibrary::Adding element Media Servers Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 19:55:12 volumio volumio[1040]: info: [1792180512394] CoreMusicLibrary::Adding element Last_100 Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 19:55:12 volumio volumio[1040]: info: [1792180512399] CoreMusicLibrary::Adding element Webradio Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 19:55:12 volumio volumio[1040]: info: Loading i18n strings for locale ru Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 19:55:12 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:12 volumio volumio[1040]: info: ----- MyVolumio plugins startup ---- Oct 16 19:55:12 volumio volumio[1040]: info: ------------------------------------------- Oct 16 19:55:12 volumio volumio[1040]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 19:55:12 volumio volumio[1040]: info: Loading i18n strings for locale ru Oct 16 19:55:12 volumio volumio[1040]: Updating browse sources language Oct 16 19:55:12 volumio volumio[1040]: Cannot find translation for sourceMedia Servers Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:12 volumio sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/hardware.conf /etc/lirc/lircd.conf /etc/lirc/lircmd.conf /etc/lirc/lircrc Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::initPlayerControls Oct 16 19:55:12 volumio volumio[1040]: Starting albumart workers Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 19:55:12 volumio sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 19:55:12 volumio volumio[1040]: Starting albumart workers Oct 16 19:55:12 volumio volumio[1040]: Starting albumart workers Oct 16 19:55:12 volumio volumio[1040]: info: BOOT COMPLETED Oct 16 19:55:12 volumio volumio[1040]: [Metrics] CommandRouter: 5s 964.11ms Oct 16 19:55:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 19:55:12 volumio sudo[1127]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:34 volumio systemd[1]: Time has been changed Oct 16 19:55:36 volumio volumio-remote-updater[600]: [2026-10-16 19:55:36] [connect] Successful connection Oct 16 19:55:39 volumio volumio[1040]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Oct 16 19:55:39 volumio volumio[1040]: info: CoreCommandRouter::Close All Modals sent Oct 16 19:55:39 volumio volumio[1040]: info: CoreCommandRouter::Close All Modals sent Oct 16 19:55:39 volumio volumio[1040]: Express server listening on port 3000 Oct 16 19:55:39 volumio volumio[1040]: [Metrics] WebUI: 12s 225.74ms Oct 16 19:55:39 volumio volumio[1040]: Volumio Calling Home Oct 16 19:55:39 volumio volumio[1040]: info: CoreStateMachine::resetVolumioState Oct 16 19:55:39 volumio volumio[1040]: info: CoreStateMachine::getcurrentVolume Oct 16 19:55:39 volumio volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::updateTrackBlock Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrackBlock Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 19:55:40 volumio volumio[1040]: info: Setting Device type: Raspberry PI Oct 16 19:55:40 volumio volumio[1040]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Oct 16 19:55:40 volumio volumio[1040]: info: MPD running with PID664 Oct 16 19:55:40 volumio volumio[1040]: ,establishing connection Oct 16 19:55:40 volumio sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cdetect -y 1 Oct 16 19:55:40 volumio sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:40 volumio sudo[1183]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:40 volumio volumio-remote-updater[600]: [2026-10-16 19:55:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1792180536 101 Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:40 volumio volumio[1040]: info: Oct 16 19:55:40 volumio volumio[1040]: ---------------------------- Client requests Volume 50 Oct 16 19:55:40 volumio volumio[1040]: info: VolumeController::SetAlsaVolume50 Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 19:55:40 volumio volumio[1040]: info: Reloading queue from file Oct 16 19:55:40 volumio volumio[1040]: info: null Oct 16 19:55:40 volumio volumio[1040]: info: Setting volume on startup at 50 Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::setRepeat true single undefined Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::setRandom null Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:40 volumio volumio[1040]: info: Starting Shairport Sync Oct 16 19:55:40 volumio volumio[1040]: info: Starting Shairport Sync Oct 16 19:55:40 volumio sudo[1194]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 19:55:40 volumio sudo[1194]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:40 volumio sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 19:55:40 volumio sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:40 volumio systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Oct 16 19:55:40 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 19:55:40 volumio sudo[1194]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:40 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 16 19:55:40 volumio systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Oct 16 19:55:40 volumio sudo[1196]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:40 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 16 19:55:40 volumio volumio[1040]: info: ir_controller: LIRC correctly updated. Oct 16 19:55:40 volumio volumio[1040]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Oct 16 19:55:40 volumio volumio[1040]: Discovery: adding d3baae3b-1a70-4884-b247-f96b919a671a Oct 16 19:55:40 volumio volumio[1040]: info: mDNS: Found device Volumio Oct 16 19:55:40 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 16 19:55:40 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:40 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:41 volumio volumio[1040]: info: Shairport-Sync Started Oct 16 19:55:41 volumio volumio[1040]: Error adding Membership: Error: addMembership EINVAL Oct 16 19:55:41 volumio volumio[1040]: info: Shairport-Sync Started Oct 16 19:55:41 volumio volumio[1040]: info: ir_controller: Raspberry Pi revision code: a020d3 Oct 16 19:55:41 volumio sudo[1230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 19:55:41 volumio sudo[1230]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:41 volumio sudo[1233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 19:55:41 volumio sudo[1230]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:41 volumio sudo[1233]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:41 volumio sudo[1233]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:42 volumio sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop lirc.service Oct 16 19:55:42 volumio volumio[1040]: info: ControllerAutoPlay - mpd ready Oct 16 19:55:42 volumio sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:42 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 16 19:55:42 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:42 volumio systemd[1]: Stopped LSB: Starts LIRC daemon.. Oct 16 19:55:42 volumio sudo[1248]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:42 volumio sudo[1255]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Oct 16 19:55:42 volumio sudo[1255]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:42 volumio sudo[1255]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:42 volumio volumio[1040]: info: ir_controller: systemctl stop lirc.service succeeded. Oct 16 19:55:42 volumio sudo[1268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 19:55:42 volumio sudo[1268]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:42 volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Oct 16 19:55:42 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 16 19:55:42 volumio sudo[1268]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:42 volumio sudo[1276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=25 gpio_pull=up Oct 16 19:55:42 volumio dhcpcd[513]: timed out Oct 16 19:55:42 volumio dhcpcd[513]: exited Oct 16 19:55:42 volumio ifup[479]: dhcpcd[513]: timed out Oct 16 19:55:42 volumio ifup[479]: dhcpcd[513]: exited Oct 16 19:55:42 volumio ifup[479]: Failed to bring up eth0. Oct 16 19:55:42 volumio sudo[1276]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:42 volumio volumio[1040]: info: Upmpdcli Daemon Started Oct 16 19:55:42 volumio sudo[1276]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:42 volumio kernel: Registered IR keymap rc-rc6-mce Oct 16 19:55:42 volumio kernel: IR RC6 protocol handler initialized Oct 16 19:55:42 volumio volumio[1040]: info: ir_controller: Overlay gpio-ir gpio_pin=25 gpio_pull=up loaded. Oct 16 19:55:42 volumio kernel: rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0 Oct 16 19:55:42 volumio kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0/input2 Oct 16 19:55:42 volumio kernel: rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Oct 16 19:55:42 volumio sudo[1316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop lirc.service Oct 16 19:55:42 volumio sudo[1316]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:42 volumio systemd[1]: Stopped LSB: Starts LIRC daemon.. Oct 16 19:55:42 volumio sudo[1316]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:42 volumio systemd[1]: Starting LSB: Starts LIRC daemon.... Oct 16 19:55:42 volumio volumio[1040]: info: ir_controller: systemctl stop lirc.service succeeded. Oct 16 19:55:42 volumio lirc[1336]: Loading LIRC modules:. Oct 16 19:55:42 volumio lircd-0.9.0-pre1[1347]: lircd(default) ready, using /var/run/lirc/lircd Oct 16 19:55:42 volumio lirc[1336]: Starting remote control daemon(s) : LIRC :. Oct 16 19:55:42 volumio kernel: input: lircd as /devices/virtual/input/input3 Oct 16 19:55:42 volumio lircd-0.9.0-pre1[1347]: accepted new client on /var/run/lirc/lircd Oct 16 19:55:42 volumio lirc[1336]: Starting execution daemon: irexec:. Oct 16 19:55:42 volumio systemd[1]: Started LSB: Starts LIRC daemon.. Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 16 19:55:43 volumio sudo[1352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start lirc.service Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 16 19:55:43 volumio sudo[1352]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 16 19:55:43 volumio volumio[1040]: info: Adding plugin bluetooth to MyMusic Plugins Oct 16 19:55:43 volumio systemd[1]: Started LSB: Starts LIRC daemon.. Oct 16 19:55:43 volumio volumio[1040]: info: Adding plugin cd_controller to MyMusic Plugins Oct 16 19:55:43 volumio sudo[1352]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:43 volumio volumio[1040]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 16 19:55:43 volumio volumio[1040]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 16 19:55:45 volumio volumio[1040]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 16 19:55:46 volumio volumio[1040]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 16 19:55:46 volumio volumio[1040]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 16 19:55:46 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 19:55:46 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 19:55:46 volumio volumio[1040]: info: Starting MyVolumio Remote Streaming Endpoints Oct 16 19:55:46 volumio volumio[1040]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 16 19:55:46 volumio volumio[1040]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 16 19:55:46 volumio volumio[1040]: info: Streaming services startup Oct 16 19:55:46 volumio volumio[1040]: info: Starting Streaming Daemon Oct 16 19:55:46 volumio volumio[1040]: info: MyVolumio not started Oct 16 19:55:46 volumio volumio[1040]: info: Initializing device activation check Oct 16 19:55:46 volumio sudo[1364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 19:55:46 volumio sudo[1364]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:46 volumio systemd[1]: Stopping Volumio Streaming Daemon... Oct 16 19:55:46 volumio volumio[1040]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 16 19:55:46 volumio systemd[1]: Starting Volumio Streaming Daemon... Oct 16 19:55:46 volumio systemd[1]: Started Volumio Streaming Daemon. Oct 16 19:55:46 volumio sudo[1364]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:46 volumio volumio-streaming-daemon[1370]: ############################ Oct 16 19:55:46 volumio volumio-streaming-daemon[1370]: # Volumio Streaming Daemon # Oct 16 19:55:46 volumio volumio-streaming-daemon[1370]: # Running on port 7777 # Oct 16 19:55:46 volumio volumio-streaming-daemon[1370]: ############################ Oct 16 19:55:46 volumio volumio-streaming-daemon[1370]: Environment: production Oct 16 19:55:46 volumio volumio[1040]: info: ir_controller: systemctl start lirc.service succeeded. Oct 16 19:55:46 volumio sudo[1379]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start lirc.service Oct 16 19:55:46 volumio sudo[1379]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 19:55:46 volumio systemd[1]: Started LSB: Starts LIRC daemon.. Oct 16 19:55:46 volumio sudo[1379]: pam_unix(sudo:session): session closed for user root Oct 16 19:55:46 volumio volumio[1040]: info: ir_controller: systemctl start lirc.service succeeded. Oct 16 19:55:46 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 16 19:55:46 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:46 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:46 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 19:55:46 volumio volumio[1040]: info: Listing playlists Oct 16 19:55:46 volumio volumio[1040]: info: CoreCommandRouter::volumioGetQueue Oct 16 19:55:46 volumio volumio[1040]: info: CoreStateMachine::getQueue Oct 16 19:55:46 volumio volumio[1040]: info: CorePlayQueue::getQueue Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:47 volumio volumio[1040]: info: ControllerAutoPlay - getting queue Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioGetQueue Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::getQueue Oct 16 19:55:47 volumio volumio[1040]: info: CorePlayQueue::getQueue Oct 16 19:55:47 volumio volumio[1040]: info: ControllerAutoPlay - start playing -> queue is not empty Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioPlay Oct 16 19:55:47 volumio volumio[1040]: UNSET VOLATILE Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::play index undefined Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 19:55:47 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::startPlaybackTimer Oct 16 19:55:47 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:47 volumio volumio[1040]: info: [1792180547026] ControllerWebradio::clearAddPlayTrack Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand stop Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand clear Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:47 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand load "http://nashe1.hostingradio.ru:80/jazz-256" Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: null Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 275ms Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand add "http://nashe1.hostingradio.ru:80/jazz-256" Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:47 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand play Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 27ms Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:47 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:47 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:47 volumio volumio[1040]: info: Oct 16 19:55:47 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:55:47 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:47 volumio volumio[1040]: info: 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":"256 Kbps","isStreaming":false,"title":"Chet Baker - I Fall In Love Too Easily","artist":"Radio Jazz 89.1 FM","album":null,"uri":"http://nashe1.hostingradio.ru:80/jazz-256","trackType":""} Oct 16 19:55:47 volumio volumio[1040]: info: CURRENT POSITION 0 Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 69ms Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 39ms Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 38ms Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: sending command... Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: parsing response... Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:55:47 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:47 volumio volumio[1040]: info: STATE SERVICE {"status":"play","position":0,"seek":478,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Chet Baker - I Fall In Love Too Easily","artist":"Radio Jazz 89.1 FM","album":null,"uri":"http://nashe1.hostingradio.ru:80/jazz-256","trackType":""} Oct 16 19:55:47 volumio volumio[1040]: info: CURRENT POSITION 0 Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 16 19:55:47 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:47 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:55:47 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:47 volumio volumio[1040]: info: STATE SERVICE {"status":"play","position":0,"seek":478,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Chet Baker - I Fall In Love Too Easily","artist":"Radio Jazz 89.1 FM","album":null,"uri":"http://nashe1.hostingradio.ru:80/jazz-256","trackType":""} Oct 16 19:55:47 volumio volumio[1040]: info: CURRENT POSITION 0 Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 16 19:55:47 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:47 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 84ms Oct 16 19:55:47 volumio volumio[1040]: info: ------------------------------ 84ms Oct 16 19:55:49 volumio volumio-streaming-daemon[1370]: Environment: production Oct 16 19:55:49 volumio volumio[1040]: info: Fetching Streaming Services browse cache Oct 16 19:55:49 volumio volumio[1040]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesTIDAL Oct 16 19:55:49 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:49 volumio volumio[1040]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesQOBUZ Oct 16 19:55:49 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 19:55:50 volumio volumio[1040]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.773&uuid=8b4da437586d435a3f212bc7af0c9038" http://updates.volumio.org:7070/downloader-v1/track-device Oct 16 19:55:50 volumio volumio[1040]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 16 19:55:50 volumio volumio[1040]: Dload Upload Total Spent Left Speed Oct 16 19:55:50 volumio volumio[1040]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused Oct 16 19:55:50 volumio volumio[1040]: retrying in 5 seconds, trial 0 Oct 16 19:55:50 volumio volumio[1040]: Volumio Calling Home Oct 16 19:55:51 volumio kernel: rc rc0: two consecutive events of type space Oct 16 19:55:51 volumio volumio[1040]: info: Oct 16 19:55:51 volumio volumio[1040]: ---------------------------- Client requests Volumio next Oct 16 19:55:51 volumio volumio[1040]: info: CoreCommandRouter::volumioNext Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::next Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::stop Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 19:55:51 volumio volumio[1040]: UNSET VOLATILE Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::updateTrackBlock Oct 16 19:55:51 volumio volumio[1040]: info: CorePlayQueue::getTrackBlock Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:51 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:51 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:51 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::serviceStop Oct 16 19:55:51 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:55:51 volumio volumio[1040]: info: CoreCommandRouter::serviceStop Oct 16 19:55:51 volumio volumio[1040]: info: [1792180551779] ControllerWebradio::stop Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand stop Oct 16 19:55:51 volumio volumio[1040]: info: sending command... Oct 16 19:55:51 volumio volumio[1040]: info: parsing response... Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::play index undefined Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 19:55:51 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::startPlaybackTimer Oct 16 19:55:51 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:51 volumio volumio[1040]: info: [1792180551855] ControllerWebradio::clearAddPlayTrack Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand stop Oct 16 19:55:51 volumio volumio[1040]: info: sending command... Oct 16 19:55:51 volumio volumio[1040]: info: CoreStateMachine::updateTrackBlock Oct 16 19:55:51 volumio volumio[1040]: info: CorePlayQueue::getTrackBlock Oct 16 19:55:51 volumio volumio[1040]: info: Oct 16 19:55:51 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:51 volumio volumio[1040]: info: parsing response... Oct 16 19:55:51 volumio volumio[1040]: info: sending command... Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand clear Oct 16 19:55:51 volumio volumio[1040]: info: sending command... Oct 16 19:55:51 volumio volumio[1040]: info: Oct 16 19:55:51 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:51 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:51 volumio volumio[1040]: info: parsing response... Oct 16 19:55:51 volumio volumio[1040]: info: parsing response... Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand load "http://jazz128legends.streamr.ru:80/" Oct 16 19:55:51 volumio volumio[1040]: info: sending command... Oct 16 19:55:51 volumio volumio[1040]: info: sending command... Oct 16 19:55:51 volumio volumio[1040]: info: null Oct 16 19:55:51 volumio volumio[1040]: info: ------------------------------ 7ms Oct 16 19:55:51 volumio volumio[1040]: info: parsing response... Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:51 volumio volumio[1040]: info: ControllerMpd::pushError Oct 16 19:55:51 volumio volumio[1040]: info: Cannot read property 'split' of undefined Oct 16 19:55:51 volumio volumio[1040]: info: ------------------------------ 16ms Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand add "http://jazz128legends.streamr.ru:80/" Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: Oct 16 19:55:52 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:52 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand play Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: ------------------------------ 6ms Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: Oct 16 19:55:52 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: Oct 16 19:55:52 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:52 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:52 volumio volumio[1040]: info: Oct 16 19:55:52 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: Oct 16 19:55:52 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 16 19:55:52 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 16 19:55:52 volumio volumio[1040]: info: Oct 16 19:55:52 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:55:52 volumio volumio[1040]: info: ------------------------------ 10ms Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:55:52 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:52 volumio volumio[1040]: info: 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":"128 Kbps","isStreaming":false,"title":"Holiday Billie - Autumn in New York","artist":"Jazz Legends","album":null,"uri":"http://jazz128legends.streamr.ru:80/","trackType":"ru:80/"} Oct 16 19:55:52 volumio volumio[1040]: info: CURRENT POSITION 1 Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:52 volumio volumio[1040]: info: ------------------------------ 50ms Oct 16 19:55:52 volumio volumio[1040]: info: ------------------------------ 22ms Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:52 volumio volumio[1040]: info: sending command... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:55:52 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:52 volumio volumio[1040]: info: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Holiday Billie - Autumn in New York","artist":"Jazz Legends","album":null,"uri":"http://jazz128legends.streamr.ru:80/","trackType":"ru:80/"} Oct 16 19:55:52 volumio volumio[1040]: info: CURRENT POSITION 1 Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 16 19:55:52 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:52 volumio volumio[1040]: info: ------------------------------ 51ms Oct 16 19:55:52 volumio volumio[1040]: info: parsing response... Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:55:52 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:55:52 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:52 volumio volumio[1040]: info: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Holiday Billie - Autumn in New York","artist":"Jazz Legends","album":null,"uri":"http://jazz128legends.streamr.ru:80/","trackType":"ru:80/"} Oct 16 19:55:52 volumio volumio[1040]: info: CURRENT POSITION 1 Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 16 19:55:52 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:52 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:55:52 volumio volumio[1040]: info: ------------------------------ 68ms Oct 16 19:55:53 volumio volumio[1040]: info: AutoStart - getting queue Oct 16 19:55:53 volumio volumio[1040]: info: CoreCommandRouter::volumioGetQueue Oct 16 19:55:53 volumio volumio[1040]: info: CoreStateMachine::getQueue Oct 16 19:55:53 volumio volumio[1040]: info: CorePlayQueue::getQueue Oct 16 19:55:53 volumio volumio[1040]: info: AutoStart - start playing -> queue is not empty Oct 16 19:55:53 volumio volumio[1040]: info: CoreCommandRouter::volumioPlay Oct 16 19:55:53 volumio volumio[1040]: UNSET VOLATILE Oct 16 19:55:53 volumio volumio[1040]: info: CoreStateMachine::play index undefined Oct 16 19:55:53 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 19:55:53 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:56 volumio volumio[1040]: info: Oct 16 19:55:56 volumio volumio[1040]: ---------------------------- Client requests Volume - Oct 16 19:55:56 volumio volumio[1040]: info: VolumeController::SetAlsaVolume- Oct 16 19:55:56 volumio volumio[1040]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Oct 16 19:55:56 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:55:56 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:55:56 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:55:56 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:55:56 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:00 volumio volumio[1040]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.773&uuid=8b4da437586d435a3f212bc7af0c9038" http://updates.volumio.org:7070/downloader-v1/track-device Oct 16 19:56:00 volumio volumio[1040]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 16 19:56:00 volumio volumio[1040]: Dload Upload Total Spent Left Speed Oct 16 19:56:00 volumio volumio[1040]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused Oct 16 19:56:00 volumio volumio[1040]: retrying in 5 seconds, trial 1 Oct 16 19:56:00 volumio volumio[1040]: Volumio Calling Home Oct 16 19:56:03 volumio volumio[1040]: info: VolumeController::SetAlsaVolume0 Oct 16 19:56:03 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:56:03 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:03 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:03 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:56:03 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:04 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 19:56:04 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 19:56:10 volumio volumio[1040]: info: Oct 16 19:56:10 volumio volumio[1040]: ---------------------------- Client requests Volume - Oct 16 19:56:10 volumio volumio[1040]: info: VolumeController::SetAlsaVolume- Oct 16 19:56:10 volumio volumio[1040]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Oct 16 19:56:10 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:56:10 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:10 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:10 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:56:10 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:10 volumio volumio[1040]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.773&uuid=8b4da437586d435a3f212bc7af0c9038" http://updates.volumio.org:7070/downloader-v1/track-device Oct 16 19:56:10 volumio volumio[1040]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 16 19:56:10 volumio volumio[1040]: Dload Upload Total Spent Left Speed Oct 16 19:56:10 volumio volumio[1040]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused Oct 16 19:56:10 volumio volumio[1040]: retrying in 5 seconds, trial 2 Oct 16 19:56:10 volumio volumio[1040]: Volumio Calling Home Oct 16 19:56:12 volumio volumio[1040]: info: Oct 16 19:56:12 volumio volumio[1040]: ---------------------------- Client requests Volume + Oct 16 19:56:12 volumio volumio[1040]: info: VolumeController::SetAlsaVolume+ Oct 16 19:56:12 volumio volumio[1040]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Oct 16 19:56:12 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:56:12 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:12 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:12 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:56:12 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:14 volumio volumio[1040]: info: Oct 16 19:56:14 volumio volumio[1040]: ---------------------------- Client requests Volumio toggle Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::volumioToggle Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:14 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::stop Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 19:56:14 volumio volumio[1040]: UNSET VOLATILE Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::updateTrackBlock Oct 16 19:56:14 volumio volumio[1040]: info: CorePlayQueue::getTrackBlock Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:14 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::serviceStop Oct 16 19:56:14 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::serviceStop Oct 16 19:56:14 volumio volumio[1040]: info: [1792180574460] ControllerWebradio::stop Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand stop Oct 16 19:56:14 volumio volumio[1040]: info: sending command... Oct 16 19:56:14 volumio volumio[1040]: info: parsing response... Oct 16 19:56:14 volumio volumio[1040]: info: Oct 16 19:56:14 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::getState Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand status Oct 16 19:56:14 volumio volumio[1040]: info: sending command... Oct 16 19:56:14 volumio volumio[1040]: info: parsing response... Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::parseState Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::sendMpdCommand playlistinfo Oct 16 19:56:14 volumio volumio[1040]: info: sending command... Oct 16 19:56:14 volumio volumio[1040]: info: parsing response... Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::parseTrackInfo Oct 16 19:56:14 volumio volumio[1040]: info: ControllerMpd::pushState Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::syncState Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:56:14 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:14 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:56:14 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:14 volumio volumio[1040]: info: CorePlayQueue::getTrack 1 Oct 16 19:56:14 volumio volumio[1040]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 16 19:56:14 volumio volumio[1040]: info: ------------------------------ 16ms Oct 16 19:56:17 volumio volumio[1040]: info: Oct 16 19:56:17 volumio volumio[1040]: ---------------------------- Client requests Volumio previous Oct 16 19:56:17 volumio volumio[1040]: info: CoreCommandRouter::volumioPrevious Oct 16 19:56:17 volumio volumio[1040]: info: CoreStateMachine::previous Oct 16 19:56:17 volumio volumio[1040]: info: CoreStateMachine::updateTrackBlock Oct 16 19:56:17 volumio volumio[1040]: info: CorePlayQueue::getTrackBlock Oct 16 19:56:17 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 16 19:56:17 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:17 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:56:17 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 16 19:56:17 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 19:56:28 volumio wpa_supplicant[919]: wlan0: CTRL-EVENT-DISCONNECTED bssid=70:4d:7b:d7:30:2c reason=3 locally_generated=1 Oct 16 19:56:28 volumio dhcpcd[1017]: wlan0: carrier lost Oct 16 19:56:28 volumio dhcpcd[1017]: wlan0: deleting host route to 192.168.1.145 via 127.0.0.1 Oct 16 19:56:28 volumio dhcpcd[1017]: wlan0: deleting route to 192.168.1.0/24 Oct 16 19:56:28 volumio dhcpcd[1017]: wlan0: deleting default route via 192.168.1.1 Oct 16 19:56:28 volumio avahi-daemon[651]: Withdrawing address record for 192.168.1.145 on wlan0. Oct 16 19:56:28 volumio avahi-daemon[651]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.145. Oct 16 19:56:28 volumio avahi-daemon[651]: Interface wlan0.IPv4 no longer relevant for mDNS. Oct 16 19:56:28 volumio wpa_supplicant[919]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Oct 16 19:56:28 volumio volumio[1040]: info: mDNS: A device disapperared from network Oct 16 19:56:28 volumio volumio[1040]: info: mDNS: Device volumio disapperared from network Oct 16 19:56:29 volumio ntpd[733]: Deleting interface #3 wlan0, 192.168.1.145#123, interface stats: received=17, sent=19, dropped=0, active_time=64 secs Oct 16 19:56:29 volumio ntpd[733]: 195.90.182.235 interface 192.168.1.145 -> (none) Oct 16 19:56:29 volumio ntpd[733]: 213.108.170.26 interface 192.168.1.145 -> (none) Oct 16 19:56:29 volumio ntpd[733]: 162.159.200.123 interface 192.168.1.145 -> (none) Oct 16 19:56:29 volumio ntpd[733]: 195.112.113.253 interface 192.168.1.145 -> (none) Oct 16 19:56:29 volumio ntpd[733]: peers refreshed Oct 16 19:56:30 volumio wpa_supplicant[919]: wlan0: Trying to associate with SSID 'ASUS_5G' Oct 16 19:56:33 volumio wpa_supplicant[919]: wlan0: Associated with 70:4d:7b:d7:30:2c Oct 16 19:56:33 volumio wpa_supplicant[919]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=FR Oct 16 19:56:33 volumio wpa_supplicant[919]: wlan0: WPA: Key negotiation completed with 70:4d:7b:d7:30:2c [PTK=CCMP GTK=CCMP] Oct 16 19:56:33 volumio wpa_supplicant[919]: wlan0: CTRL-EVENT-CONNECTED - Connection to 70:4d:7b:d7:30:2c completed [id=0 id_str=] Oct 16 19:56:33 volumio dhcpcd[1017]: wlan0: carrier acquired Oct 16 19:56:33 volumio dhcpcd[1017]: wlan0: rebinding lease of 192.168.1.145 Oct 16 19:56:33 volumio dhcpcd[1017]: wlan0: leased 192.168.1.145 for 86400 seconds Oct 16 19:56:33 volumio avahi-daemon[651]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.145. Oct 16 19:56:33 volumio avahi-daemon[651]: New relevant interface wlan0.IPv4 for mDNS. Oct 16 19:56:33 volumio avahi-daemon[651]: Registering new address record for 192.168.1.145 on wlan0.IPv4. Oct 16 19:56:33 volumio dhcpcd[1017]: wlan0: adding host route to 192.168.1.145 via 127.0.0.1 Oct 16 19:56:33 volumio dhcpcd[1017]: wlan0: adding route to 192.168.1.0/24 Oct 16 19:56:33 volumio dhcpcd[1017]: wlan0: adding default route via 192.168.1.1 Oct 16 19:56:34 volumio volumio[1040]: Discovery: adding d3baae3b-1a70-4884-b247-f96b919a671a Oct 16 19:56:34 volumio volumio[1040]: info: mDNS: Found device Volumio Oct 16 19:56:34 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 16 19:56:34 volumio volumio[1040]: info: CoreStateMachine::getState Oct 16 19:56:34 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 16 19:56:34 volumio volumio[1040]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 19:56:34 volumio volumio[1040]: Error: The value NaN is not a number Oct 16 19:56:34 volumio volumio[1040]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Oct 16 19:56:34 volumio volumio[1040]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Oct 16 19:56:34 volumio volumio[1040]: at ControllerVolumioDiscovery.pushMultiRoomStatusUpdate (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:286:25) Oct 16 19:56:34 volumio volumio[1040]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:275:10) Oct 16 19:56:34 volumio volumio[1040]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:202:12) Oct 16 19:56:34 volumio volumio[1040]: at emitTwo (events.js:126:13) Oct 16 19:56:34 volumio volumio[1040]: at Browser.emit (events.js:214:7) Oct 16 19:56:34 volumio volumio[1040]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Oct 16 19:56:34 volumio volumio[1040]: at next (/volumio/node_modules/mdns/lib/browser.js:104:7) Oct 16 19:56:34 volumio volumio[1040]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Oct 16 19:56:34 volumio volumio[1040]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Oct 16 19:56:34 volumio volumio[1040]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Oct 16 19:56:34 volumio volumio[1040]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 19:56:34 volumio ntpd[733]: Listen normally on 4 wlan0 192.168.1.145 UDP 123 Oct 16 19:56:34 volumio ntpd[733]: peers refreshed Oct 16 19:56:35 volumio sudo[1600]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-10-16 19:55 Oct 16 19:56:35 volumio sudo[1600]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ac2a0afddd424ea15d982b8c75eeec3a8648a313" VOLUMIO_FE_VERSION="700492006632ef61a5a17e6a3be4f37c790f883c" VOLUMIO_BE_VERSION="b2e85b2e8facd2d741f2fc40be426a34804b56fc" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue May 5 18:38:33 CEST 2020" VOLUMIO_VERSION="2.773" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="9e13d1d50d1f834c8c0294a226468074"