-- Logs begin at Thu 2019-02-14 17:11:59 +07, end at Fri 2025-10-24 19:47:50 +07. --
Oct 24 19:46:00 volumio ntpd[759]: 194.59.205.229 local addr 192.168.1.35 -> 
Oct 24 19:46:01 volumio ntpd[759]: 51.250.68.198 local addr 192.168.1.35 -> 
Oct 24 19:46:01 volumio ntpd[759]: 31.209.85.243 local addr 192.168.1.35 -> 
Oct 24 19:46:02 volumio ntpd[759]: 185.248.188.98 local addr 192.168.1.35 -> 
Oct 24 19:46:03 volumio ntpd[759]: 86.80.166.233 local addr 192.168.1.35 -> 
Oct 24 19:46:03 volumio ntpd[759]: 162.159.200.123 local addr 192.168.1.35 -> 
Oct 24 19:46:03 volumio ntpd[759]: 178.239.19.60 local addr 192.168.1.35 -> 
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-DISCONNECTED bssid=52:ff:20:80:28:d0 reason=6
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: carrier lost
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: Trying to associate with SSID 'Keenetic 2-7505'
Oct 24 19:46:07 volumio kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=RU
Oct 24 19:46:07 volumio avahi-daemon[607]: Withdrawing address record for 192.168.1.35 on wlan0.
Oct 24 19:46:07 volumio avahi-daemon[607]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.35.
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: deleting route to 192.168.1.0/24
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: deleting default route via 192.168.1.1
Oct 24 19:46:07 volumio avahi-daemon[607]: Interface wlan0.IPv4 no longer relevant for mDNS.
Oct 24 19:46:07 volumio volumio[977]: info: Discovery: A device disappeared from network
Oct 24 19:46:07 volumio volumio[977]: info: Discovery: Device volumio disappeared from network
Oct 24 19:46:07 volumio kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: Associated with 52:ff:20:80:28:d0
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-CONNECTED - Connection to 52:ff:20:80:28:d0 completed [id=0 id_str=]
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Oct 24 19:46:07 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=RU
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: carrier acquired
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: IAID 32:0e:79:4f
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: carrier lost
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: carrier acquired
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: IAID 32:0e:79:4f
Oct 24 19:46:07 volumio dhcpcd[872]: wlan0: soliciting an IPv6 router
Oct 24 19:46:08 volumio dhcpcd[872]: wlan0: rebinding lease of 192.168.1.35
Oct 24 19:46:08 volumio dhcpcd[872]: wlan0: probing address 192.168.1.35/24
Oct 24 19:46:09 volumio ntpd[759]: Deleting interface #15 wlan0, 192.168.1.35#123, interface stats: received=11, sent=12, dropped=0, active_time=11 secs
Oct 24 19:46:09 volumio ntpd[759]: 131.188.3.220 local addr 192.168.1.35 -> 
Oct 24 19:46:09 volumio ntpd[759]: 92.255.126.17 local addr 192.168.1.35 -> 
Oct 24 19:46:09 volumio ntpd[759]: 141.144.246.224 local addr 192.168.1.35 -> 
Oct 24 19:46:09 volumio ntpd[759]: 185.41.106.152 local addr 192.168.1.35 -> 
Oct 24 19:46:09 volumio ntpd[759]: 139.162.187.236 local addr 192.168.1.35 -> 
Oct 24 19:46:09 volumio ntpd[759]: 188.174.253.188 local addr 192.168.1.35 -> 
Oct 24 19:46:10 volumio volumio[977]: info: CorePlayQueue::getTrack 14
Oct 24 19:46:10 volumio volumio[977]: info: CorePlayQueue::getTrack 15
Oct 24 19:46:10 volumio volumio[977]: info: Prefetching next song
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.529764,  0] ../source3/libsmb/nmblib.c:917(send_udp)
Oct 24 19:46:11 volumio nmbd[725]:   Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530054,  0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Oct 24 19:46:11 volumio nmbd[725]:   send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530219,  0] ../source3/libsmb/nmblib.c:917(send_udp)
Oct 24 19:46:11 volumio nmbd[725]:   Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530354,  0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Oct 24 19:46:11 volumio nmbd[725]:   send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530491,  0] ../source3/libsmb/nmblib.c:917(send_udp)
Oct 24 19:46:11 volumio nmbd[725]:   Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530632,  0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Oct 24 19:46:11 volumio nmbd[725]:   send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530769,  0] ../source3/libsmb/nmblib.c:917(send_udp)
Oct 24 19:46:11 volumio nmbd[725]:   Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.530896,  0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Oct 24 19:46:11 volumio nmbd[725]:   send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.531028,  0] ../source3/libsmb/nmblib.c:917(send_udp)
Oct 24 19:46:11 volumio nmbd[725]:   Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.531154,  0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Oct 24 19:46:11 volumio nmbd[725]:   send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.544066,  0] ../source3/libsmb/nmblib.c:917(send_udp)
Oct 24 19:46:11 volumio nmbd[725]:   Packet send failed to 192.168.1.255(137) ERRNO=Network is unreachable
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.544352,  0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Oct 24 19:46:11 volumio nmbd[725]:   send_netbios_packet: send_packet() to IP 192.168.1.255 port 137 failed
Oct 24 19:46:11 volumio nmbd[725]: [2025/10/24 19:46:11.544490,  0] ../source3/nmbd/nmbd_namequery.c:245(query_name)
Oct 24 19:46:11 volumio nmbd[725]:   query_name: Failed to send packet trying to query name WORKGROUP<1d>
Oct 24 19:46:13 volumio dhcpcd[872]: wlan0: leased 192.168.1.35 for 25200 seconds
Oct 24 19:46:13 volumio avahi-daemon[607]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.35.
Oct 24 19:46:13 volumio dhcpcd[872]: wlan0: adding route to 192.168.1.0/24
Oct 24 19:46:13 volumio dhcpcd[872]: wlan0: adding default route via 192.168.1.1
Oct 24 19:46:13 volumio avahi-daemon[607]: New relevant interface wlan0.IPv4 for mDNS.
Oct 24 19:46:13 volumio avahi-daemon[607]: Registering new address record for 192.168.1.35 on wlan0.IPv4.
Oct 24 19:46:15 volumio ntpd[759]: Listen normally on 16 wlan0 192.168.1.35:123
Oct 24 19:46:15 volumio ntpd[759]: new interface(s) found: waking up resolver
Oct 24 19:46:15 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer
Oct 24 19:46:15 volumio volumio[977]: info: CorePlayQueue::getTrack 15
Oct 24 19:46:15 volumio volumio[977]: info: Discovery: adding 1b7efee1-ab32-414f-bc94-56e1d0d385ab
Oct 24 19:46:15 volumio volumio[977]: info: Discovery: Found device Volumio
Oct 24 19:46:15 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:46:15 volumio volumio[977]: info: CorePlayQueue::getTrack 15
Oct 24 19:46:15 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:15 volumio volumio[977]: info: CorePlayQueue::getTrack 15
Oct 24 19:46:15 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:15 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:15 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:16 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:16 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:16 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:16 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:46:16 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:46:16 volumio kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 2 ep 1
Oct 24 19:46:16 volumio kernel: xhci_hcd 0000:01:00.0: @0000000429522f80 00000000 00000000 0e000000 02028000
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 9ms
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand status took 8 milliseconds
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 7ms
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand status took 6 milliseconds
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 6ms
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:16 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 15
Oct 24 19:46:16 volumio volumio[977]: 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}
Oct 24 19:46:16 volumio volumio[977]: verbose: CURRENT POSITION 15
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::syncState   stateService stop
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::play index undefined
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:16 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current yandex_music Received mpd
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 47ms
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 46ms
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand status took 67 milliseconds
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand stop took 26 milliseconds
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand clear
Oct 24 19:46:16 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:16 volumio volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current yandex_music Received mpd
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 81ms
Oct 24 19:46:16 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:16 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand clear took 34 milliseconds
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:46:16 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:46:16 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 12ms
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 5ms
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac"
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac" took 4 milliseconds
Oct 24 19:46:16 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:46:16 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 11ms
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 8ms
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 8ms
Oct 24 19:46:16 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 24 19:46:16 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand play
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info:
Oct 24 19:46:16 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:46:16 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 12ms
Oct 24 19:46:16 volumio volumio[977]: info: sendMpdCommand play took 5 milliseconds
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 4ms
Oct 24 19:46:16 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:46:17 volumio volumio[977]: info:
Oct 24 19:46:17 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:17 volumio volumio[977]: info:
Oct 24 19:46:17 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:17 volumio volumio[977]: info:
Oct 24 19:46:17 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:17 volumio volumio[977]: info:
Oct 24 19:46:17 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand status took 10 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand status took 8 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand status took 7 milliseconds
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:46:17 volumio volumio[977]: info:
Oct 24 19:46:17 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand status took 15 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand playlistinfo took 14 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand playlistinfo took 13 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand playlistinfo took 12 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand status took 9 milliseconds
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:17 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Город теней: припять","artist":"Essecer","album":"Город теней: припять","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:46:17 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus stop
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:17 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Город теней: припять","artist":"Essecer","album":"Город теней: припять","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:46:17 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:46:17 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:17 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Город теней: припять","artist":"Essecer","album":"Город теней: припять","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:46:17 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:46:17 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: ------------------------------ 63ms
Oct 24 19:46:17 volumio volumio[977]: info: ------------------------------ 93ms
Oct 24 19:46:17 volumio volumio[977]: info: ------------------------------ 90ms
Oct 24 19:46:17 volumio volumio[977]: info:
Oct 24 19:46:17 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand playlistinfo took 79 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand playlistinfo took 76 milliseconds
Oct 24 19:46:17 volumio volumio[977]: info: sendMpdCommand status took 12 milliseconds
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:46:17 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:17 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":480,"duration":226,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"935 Kbps","isStreaming":false,"title":"Город теней: припять","artist":"Essecer","album":"Город теней: припять","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:46:17 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:46:17 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:17 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":226,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"935 Kbps","isStreaming":false,"title":"Город теней: припять","artist":"Essecer","album":"Город теней: припять","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:46:17 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:46:17 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:17 volumio volumio[977]: info: ------------------------------ 146ms
Oct 24 19:46:17 volumio volumio[977]: info: ------------------------------ 139ms
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:17 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:17 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:17 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: sendMpdCommand playlistinfo took 696 milliseconds
Oct 24 19:46:18 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:46:18 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:46:18 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":226,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"935 Kbps","isStreaming":false,"title":"Город теней: припять","artist":"Essecer","album":"Город теней: припять","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da64876240e54ee012c06b69ab58acfe771f8cb602006d290809a9d38f7e41a8f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908b677%2F0%2F12930036%2F8378a353.206079410.5.141173474%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:46:18 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:46:18 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:46:18 volumio volumio[977]: info: ------------------------------ 732ms
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioAddQueueItems
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::addQueueItems
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::addQueueItems
Oct 24 19:46:18 volumio volumio[977]: info: Preload queue cleared
Oct 24 19:46:18 volumio volumio[977]: info: Adding Item to queue: yandex_music/track/141432585:37607361@user:onyourwave
Oct 24 19:46:18 volumio volumio[977]: info: Exploding uri yandex_music/track/141432585:37607361@user:onyourwave in service yandex_music
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::saveQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getTrackBlock
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:46:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:46:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:46:21 volumio ntpd[759]: Soliciting pool server 2a03:b020:0:403::254
Oct 24 19:46:23 volumio ntpd[759]: Soliciting pool server 144.76.139.8
Oct 24 19:46:23 volumio ntpd[759]: Soliciting pool server 217.154.242.106
Oct 24 19:46:24 volumio ntpd[759]: Soliciting pool server 188.68.34.173
Oct 24 19:46:24 volumio ntpd[759]: Soliciting pool server 151.22.209.90
Oct 24 19:46:25 volumio ntpd[759]: Soliciting pool server 77.37.65.181
Oct 24 19:46:25 volumio ntpd[759]: Soliciting pool server 129.152.16.145
Oct 24 19:46:26 volumio ntpd[759]: Soliciting pool server 94.16.122.152
Oct 24 19:46:26 volumio ntpd[759]: Soliciting pool server 93.94.88.51
Oct 24 19:46:27 volumio ntpd[759]: Soliciting pool server 89.46.74.148
Oct 24 19:46:33 volumio ntpd[759]: Soliciting pool server 80.60.67.39
Oct 24 19:47:12 volumio volumio[977]: info: CoreCommandRouter::volumioNext
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::next
Oct 24 19:47:12 volumio volumio[977]: info: ControllerMpd::next
Oct 24 19:47:12 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand next
Oct 24 19:47:12 volumio volumio[977]: info:
Oct 24 19:47:12 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:12 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:12 volumio volumio[977]: info:
Oct 24 19:47:12 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:12 volumio volumio[977]: info: sendMpdCommand next took 23 milliseconds
Oct 24 19:47:12 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:12 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:12 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:12 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:12 volumio volumio[977]: info: sendMpdCommand status took 2 milliseconds
Oct 24 19:47:12 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:12 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:12 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:12 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:12 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:12 volumio volumio[977]: info: CorePlayQueue::getTrack 16
Oct 24 19:47:12 volumio volumio[977]: 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}
Oct 24 19:47:12 volumio volumio[977]: verbose: CURRENT POSITION 16
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::syncState   stateService stop
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::play index undefined
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 24 19:47:12 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:12 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:12 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:12 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 27ms
Oct 24 19:47:13 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:13 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:13 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:13 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:13 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:13 volumio volumio[977]: info: sendMpdCommand stop took 40 milliseconds
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 6ms
Oct 24 19:47:13 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 4ms
Oct 24 19:47:13 volumio volumio[977]: info: sendMpdCommand status took 3 milliseconds
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand clear
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:13 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:13 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current yandex_music Received mpd
Oct 24 19:47:13 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:13 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:13 volumio volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current yandex_music Received mpd
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 27ms
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 26ms
Oct 24 19:47:13 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:13 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:13 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info: sendMpdCommand clear took 43 milliseconds
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 16ms
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 7ms
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 6ms
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac"
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info: sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac" took 2 milliseconds
Oct 24 19:47:13 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:47:13 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 7ms
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 4ms
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:13 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 24 19:47:13 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand play
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info:
Oct 24 19:47:13 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:13 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 9ms
Oct 24 19:47:13 volumio volumio[977]: info: sendMpdCommand play took 7 milliseconds
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 4ms
Oct 24 19:47:13 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:14 volumio volumio[977]: info:
Oct 24 19:47:14 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:14 volumio volumio[977]: info:
Oct 24 19:47:14 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand status took 2 milliseconds
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:14 volumio volumio[977]: info:
Oct 24 19:47:14 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:14 volumio volumio[977]: info:
Oct 24 19:47:14 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand status took 9 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand playlistinfo took 9 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand status took 7 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand status took 7 milliseconds
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:14 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"А вам меня не сломать","artist":"Garik Garik","album":"А вам меня не сломать","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:14 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus stop
Oct 24 19:47:14 volumio volumio[977]: info: ------------------------------ 18ms
Oct 24 19:47:14 volumio volumio[977]: info:
Oct 24 19:47:14 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:14 volumio volumio[977]: info:
Oct 24 19:47:14 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand playlistinfo took 11 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand playlistinfo took 9 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand playlistinfo took 9 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand status took 6 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:14 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"А вам меня не сломать","artist":"Garik Garik","album":"А вам меня не сломать","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:14 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:14 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:14 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"А вам меня не сломать","artist":"Garik Garik","album":"А вам меня не сломать","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:14 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:14 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:14 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"А вам меня не сломать","artist":"Garik Garik","album":"А вам меня не сломать","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:14 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:14 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: ------------------------------ 93ms
Oct 24 19:47:14 volumio volumio[977]: info: ------------------------------ 91ms
Oct 24 19:47:14 volumio volumio[977]: info: ------------------------------ 91ms
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand playlistinfo took 70 milliseconds
Oct 24 19:47:14 volumio volumio[977]: info: sendMpdCommand playlistinfo took 70 milliseconds
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:14 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:14 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"А вам меня не сломать","artist":"Garik Garik","album":"А вам меня не сломать","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:14 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:14 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:14 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"А вам меня не сломать","artist":"Garik Garik","album":"А вам меня не сломать","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2926350375df5c7c49cf44b597e5a85fdabc4edc3fcd34bfa485f2628bec219f%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D6908f304%2F0%2F1543886%2F8ab2b71d.209660614.5.144109576%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:14 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:14 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:14 volumio volumio[977]: info: ------------------------------ 123ms
Oct 24 19:47:14 volumio volumio[977]: info: ------------------------------ 123ms
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:14 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:14 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:15 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:15 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:15 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:15 volumio volumio[977]: info: CoreCommandRouter::volumioAddQueueItems
Oct 24 19:47:15 volumio volumio[977]: info: CoreStateMachine::addQueueItems
Oct 24 19:47:15 volumio volumio[977]: info: CorePlayQueue::addQueueItems
Oct 24 19:47:15 volumio volumio[977]: info: Preload queue cleared
Oct 24 19:47:15 volumio volumio[977]: info: Adding Item to queue: yandex_music/track/119848826:28466700@user:onyourwave
Oct 24 19:47:15 volumio volumio[977]: info: Exploding uri yandex_music/track/119848826:28466700@user:onyourwave in service yandex_music
Oct 24 19:47:15 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue
Oct 24 19:47:15 volumio volumio[977]: info: CorePlayQueue::saveQueue
Oct 24 19:47:15 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock
Oct 24 19:47:15 volumio volumio[977]: info: CorePlayQueue::getTrackBlock
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioNext
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::next
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::next
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand next
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:18 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:18 volumio volumio[977]: info: sendMpdCommand next took 34 milliseconds
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:18 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:18 volumio volumio[977]: info: sendMpdCommand status took 1 milliseconds
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 17
Oct 24 19:47:18 volumio volumio[977]: 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}
Oct 24 19:47:18 volumio volumio[977]: verbose: CURRENT POSITION 17
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::syncState   stateService stop
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::play index undefined
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 30ms
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:18 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:18 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:18 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:18 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:18 volumio volumio[977]: info: sendMpdCommand stop took 29 milliseconds
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 11ms
Oct 24 19:47:18 volumio volumio[977]: info: sendMpdCommand status took 10 milliseconds
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 9ms
Oct 24 19:47:18 volumio volumio[977]: info: sendMpdCommand status took 4 milliseconds
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand clear
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:18 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current yandex_music Received mpd
Oct 24 19:47:18 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:18 volumio volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current yandex_music Received mpd
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 39ms
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 38ms
Oct 24 19:47:18 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:18 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:18 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:18 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:18 volumio volumio[977]: info: sendMpdCommand clear took 42 milliseconds
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:18 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:18 volumio volumio[977]: info:
Oct 24 19:47:18 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:18 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:18 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 11ms
Oct 24 19:47:18 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-DISCONNECTED bssid=52:ff:20:80:28:d0 reason=6
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: carrier lost
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: Trying to associate with SSID 'Keenetic 2-7505'
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Oct 24 19:47:23 volumio kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=RU
Oct 24 19:47:23 volumio avahi-daemon[607]: Withdrawing address record for 192.168.1.35 on wlan0.
Oct 24 19:47:23 volumio avahi-daemon[607]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.35.
Oct 24 19:47:23 volumio avahi-daemon[607]: Interface wlan0.IPv4 no longer relevant for mDNS.
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: deleting route to 192.168.1.0/24
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: deleting default route via 192.168.1.1
Oct 24 19:47:23 volumio volumio[977]: info: Discovery: A device disappeared from network
Oct 24 19:47:23 volumio volumio[977]: info: Discovery: Device volumio disappeared from network
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: Associated with 52:ff:20:80:28:d0
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-CONNECTED - Connection to 52:ff:20:80:28:d0 completed [id=0 id_str=]
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Oct 24 19:47:23 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=RU
Oct 24 19:47:23 volumio kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: carrier acquired
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: IAID 32:0e:79:4f
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: carrier lost
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: carrier acquired
Oct 24 19:47:23 volumio dhcpcd[872]: wlan0: IAID 32:0e:79:4f
Oct 24 19:47:24 volumio dhcpcd[872]: wlan0: soliciting an IPv6 router
Oct 24 19:47:24 volumio dhcpcd[872]: wlan0: rebinding lease of 192.168.1.35
Oct 24 19:47:24 volumio dhcpcd[872]: wlan0: probing address 192.168.1.35/24
Oct 24 19:47:25 volumio ntpd[759]: Deleting interface #16 wlan0, 192.168.1.35#123, interface stats: received=76, sent=76, dropped=0, active_time=70 secs
Oct 24 19:47:25 volumio ntpd[759]: 80.60.67.39 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 89.46.74.148 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 93.94.88.51 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 94.16.122.152 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 129.152.16.145 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 77.37.65.181 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 151.22.209.90 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 188.68.34.173 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 217.154.242.106 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 144.76.139.8 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 131.188.3.220 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 92.255.126.17 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 141.144.246.224 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 185.41.106.152 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 139.162.187.236 local addr 192.168.1.35 -> 
Oct 24 19:47:25 volumio ntpd[759]: 188.174.253.188 local addr 192.168.1.35 -> 
Oct 24 19:47:27 volumio volumio[977]: info: Volumio Network Manager: Network status updated: 0
Oct 24 19:47:29 volumio dhcpcd[872]: wlan0: leased 192.168.1.35 for 25200 seconds
Oct 24 19:47:29 volumio avahi-daemon[607]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.35.
Oct 24 19:47:29 volumio avahi-daemon[607]: New relevant interface wlan0.IPv4 for mDNS.
Oct 24 19:47:29 volumio dhcpcd[872]: wlan0: adding route to 192.168.1.0/24
Oct 24 19:47:29 volumio avahi-daemon[607]: Registering new address record for 192.168.1.35 on wlan0.IPv4.
Oct 24 19:47:29 volumio dhcpcd[872]: wlan0: adding default route via 192.168.1.1
Oct 24 19:47:31 volumio ntpd[759]: Listen normally on 17 wlan0 192.168.1.35:123
Oct 24 19:47:31 volumio ntpd[759]: new interface(s) found: waking up resolver
Oct 24 19:47:31 volumio volumio[977]: info: Discovery: adding 1b7efee1-ab32-414f-bc94-56e1d0d385ab
Oct 24 19:47:31 volumio volumio[977]: info: Discovery: Found device Volumio
Oct 24 19:47:31 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:47:31 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:31 volumio volumio[977]: info: CoreCommandRouter::volumioPlay
Oct 24 19:47:31 volumio volumio[977]: info: CoreStateMachine::play index undefined
Oct 24 19:47:31 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 24 19:47:31 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:31 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer
Oct 24 19:47:31 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:31 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop
Oct 24 19:47:31 volumio volumio[977]: info: sendMpdCommand stop took 8 milliseconds
Oct 24 19:47:31 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand clear
Oct 24 19:47:31 volumio volumio[977]: info: sendMpdCommand clear took 1 milliseconds
Oct 24 19:47:31 volumio volumio[977]: info:
Oct 24 19:47:31 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:31 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:31 volumio volumio[977]: info:
Oct 24 19:47:31 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:31 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:31 volumio volumio[977]: info:
Oct 24 19:47:31 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:31 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:31 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:31 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:31 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:31 volumio volumio[977]: info: ------------------------------ 2ms
Oct 24 19:47:31 volumio volumio[977]: error: updateQueue error: null
Oct 24 19:47:31 volumio volumio[977]: info: ------------------------------ 7ms
Oct 24 19:47:32 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac"
Oct 24 19:47:32 volumio volumio[977]: info:
Oct 24 19:47:32 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:32 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:32 volumio volumio[977]: info: sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac" took 2 milliseconds
Oct 24 19:47:32 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:47:32 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:47:32 volumio volumio[977]: info:
Oct 24 19:47:32 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:32 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:32 volumio volumio[977]: info:
Oct 24 19:47:32 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:32 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:32 volumio volumio[977]: info:
Oct 24 19:47:32 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:32 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:32 volumio volumio[977]: info: ------------------------------ 6ms
Oct 24 19:47:32 volumio volumio[977]: info: ------------------------------ 4ms
Oct 24 19:47:32 volumio volumio[977]: info: ------------------------------ 3ms
Oct 24 19:47:32 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 24 19:47:32 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand play
Oct 24 19:47:32 volumio volumio[977]: info:
Oct 24 19:47:32 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:32 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:32 volumio volumio[977]: info:
Oct 24 19:47:32 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:32 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:32 volumio volumio[977]: info: ------------------------------ 5ms
Oct 24 19:47:32 volumio volumio[977]: info: sendMpdCommand play took 4 milliseconds
Oct 24 19:47:32 volumio volumio[977]: info: ------------------------------ 4ms
Oct 24 19:47:32 volumio volumio[977]: info: ------------------------------ 2ms
Oct 24 19:47:32 volumio ntpd[759]: 92.255.126.17 local addr 192.168.1.35 -> 
Oct 24 19:47:33 volumio volumio[977]: info:
Oct 24 19:47:33 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:33 volumio volumio[977]: info:
Oct 24 19:47:33 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:33 volumio volumio[977]: info:
Oct 24 19:47:33 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:33 volumio volumio[977]: info:
Oct 24 19:47:33 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand status took 8 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand status took 7 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand playlistinfo took 5 milliseconds
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:33 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Heaven and Hell","artist":"Brutaliti","album":"Heaven and Hell","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:33 volumio volumio[977]: verbose: CURRENT POSITION 18
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus stop
Oct 24 19:47:33 volumio volumio[977]: info: ------------------------------ 15ms
Oct 24 19:47:33 volumio volumio[977]: info:
Oct 24 19:47:33 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:33 volumio volumio[977]: info:
Oct 24 19:47:33 volumio volumio[977]: ---------------------------- MPD announces state update: player
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::getState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand status took 8 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand playlistinfo took 7 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand playlistinfo took 7 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand status took 3 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand status took 3 milliseconds
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseState
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:33 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Heaven and Hell","artist":"Brutaliti","album":"Heaven and Hell","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:33 volumio volumio[977]: verbose: CURRENT POSITION 18
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:33 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:33 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Heaven and Hell","artist":"Brutaliti","album":"Heaven and Hell","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:33 volumio volumio[977]: verbose: CURRENT POSITION 18
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:33 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: ------------------------------ 67ms
Oct 24 19:47:33 volumio volumio[977]: info: ------------------------------ 66ms
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand playlistinfo took 61 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand playlistinfo took 60 milliseconds
Oct 24 19:47:33 volumio volumio[977]: info: sendMpdCommand playlistinfo took 60 milliseconds
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:33 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:33 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Heaven and Hell","artist":"Brutaliti","album":"Heaven and Hell","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:33 volumio volumio[977]: verbose: CURRENT POSITION 18
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:33 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:33 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Heaven and Hell","artist":"Brutaliti","album":"Heaven and Hell","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:33 volumio volumio[977]: verbose: CURRENT POSITION 18
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:33 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: ControllerMpd::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::servicePushState
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getTrack 18
Oct 24 19:47:33 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"44.1 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Heaven and Hell","artist":"Brutaliti","album":"Heaven and Hell","uri":"http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs02rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D44244da3b19260893ce923db4566fae92ffeaa24bb995f3c46a13c7041c9b1f4%2Clid%3D1637%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac","trackType":"flac"}
Oct 24 19:47:33 volumio volumio[977]: verbose: CURRENT POSITION 18
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   stateService play
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::syncState   currentStatus play
Oct 24 19:47:33 volumio volumio[977]: info: Received an update from plugin. extracting info from payload
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::pushState
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioPushState
Oct 24 19:47:33 volumio volumio[977]: info: ------------------------------ 134ms
Oct 24 19:47:33 volumio volumio[977]: info: ------------------------------ 129ms
Oct 24 19:47:33 volumio volumio[977]: info: ------------------------------ 129ms
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:33 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:33 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:34 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:34 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:34 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da6e63b0a0f4a93cecbafe733a83286de3f421fcfa9234bf2debd0c19565bc54b%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac"
Oct 24 19:47:34 volumio volumio[977]: info:
Oct 24 19:47:34 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:34 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:34 volumio volumio[977]: info: sendMpdCommand addid "http://localhost:6601/?codec=flac-mp4&transport=raw&key=&url=https%3A%2F%2Fext-strm-runvs01rtk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da6e63b0a0f4a93cecbafe733a83286de3f421fcfa9234bf2debd0c19565bc54b%2Clid%3D1636%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D69092b81%2F0%2F16282%2Fdbc3ed4f.199382162.6.135581673%2Fflac-mp4&ext=.flac" took 4 milliseconds
Oct 24 19:47:34 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:47:34 volumio volumio[977]: verbose: MPD COMMAND [object Object]
Oct 24 19:47:34 volumio volumio[977]: info:
Oct 24 19:47:34 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:34 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:34 volumio volumio[977]: info:
Oct 24 19:47:34 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:34 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:34 volumio volumio[977]: info:
Oct 24 19:47:34 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:34 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:34 volumio volumio[977]: info: ------------------------------ 9ms
Oct 24 19:47:34 volumio volumio[977]: info: ------------------------------ 7ms
Oct 24 19:47:34 volumio volumio[977]: info: ------------------------------ 5ms
Oct 24 19:47:34 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 24 19:47:34 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand play
Oct 24 19:47:34 volumio volumio[977]: info:
Oct 24 19:47:34 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:34 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:34 volumio volumio[977]: info:
Oct 24 19:47:34 volumio volumio[977]: ---------------------------- MPD announces system playlist update
Oct 24 19:47:34 volumio volumio[977]: info: Ignoring MPD Status Update
Oct 24 19:47:34 volumio volumio[977]: info: ------------------------------ 10ms
Oct 24 19:47:34 volumio volumio[977]: info: sendMpdCommand play took 7 milliseconds
Oct 24 19:47:34 volumio volumio[977]: info: ------------------------------ 8ms
Oct 24 19:47:34 volumio volumio[977]: info: ------------------------------ 6ms
Oct 24 19:47:34 volumio ntpd[759]: Soliciting pool server 217.160.19.219
Oct 24 19:47:35 volumio ntpd[759]: Soliciting pool server 91.98.67.74
Oct 24 19:47:35 volumio ntpd[759]: Soliciting pool server 141.144.230.32
Oct 24 19:47:35 volumio volumio[977]: info: CoreCommandRouter::volumioAddQueueItems
Oct 24 19:47:35 volumio volumio[977]: info: CoreStateMachine::addQueueItems
Oct 24 19:47:35 volumio volumio[977]: info: CorePlayQueue::addQueueItems
Oct 24 19:47:35 volumio volumio[977]: info: Preload queue cleared
Oct 24 19:47:35 volumio volumio[977]: info: Adding Item to queue: yandex_music/track/51964403:7283006@user:onyourwave
Oct 24 19:47:35 volumio volumio[977]: info: Exploding uri yandex_music/track/51964403:7283006@user:onyourwave in service yandex_music
Oct 24 19:47:35 volumio volumio[977]: info: CoreCommandRouter::volumioAddQueueItems
Oct 24 19:47:35 volumio volumio[977]: info: CoreStateMachine::addQueueItems
Oct 24 19:47:35 volumio volumio[977]: info: CorePlayQueue::addQueueItems
Oct 24 19:47:35 volumio volumio[977]: info: Preload queue cleared
Oct 24 19:47:35 volumio volumio[977]: info: Adding Item to queue: yandex_music/track/143028236:38265873@user:onyourwave
Oct 24 19:47:35 volumio volumio[977]: info: Exploding uri yandex_music/track/143028236:38265873@user:onyourwave in service yandex_music
Oct 24 19:47:35 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue
Oct 24 19:47:35 volumio volumio[977]: info: CorePlayQueue::saveQueue
Oct 24 19:47:35 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue
Oct 24 19:47:35 volumio volumio[977]: info: CorePlayQueue::saveQueue
Oct 24 19:47:35 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock
Oct 24 19:47:35 volumio volumio[977]: info: CorePlayQueue::getTrackBlock
Oct 24 19:47:35 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock
Oct 24 19:47:35 volumio volumio[977]: info: CorePlayQueue::getTrackBlock
Oct 24 19:47:36 volumio ntpd[759]: 131.188.3.220 local addr 192.168.1.35 -> 
Oct 24 19:47:36 volumio ntpd[759]: Soliciting pool server 93.177.65.20
Oct 24 19:47:37 volumio volumio[977]: info: Volumio Network Manager: Network status updated: 2
Oct 24 19:47:39 volumio ntpd[759]: Soliciting pool server 85.215.93.134
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-DISCONNECTED bssid=52:ff:20:80:28:d0 reason=6
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: carrier lost
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: Trying to associate with SSID 'Keenetic 2-7505'
Oct 24 19:47:39 volumio kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=RU
Oct 24 19:47:39 volumio avahi-daemon[607]: Withdrawing address record for 192.168.1.35 on wlan0.
Oct 24 19:47:39 volumio avahi-daemon[607]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.35.
Oct 24 19:47:39 volumio avahi-daemon[607]: Interface wlan0.IPv4 no longer relevant for mDNS.
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: deleting route to 192.168.1.0/24
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: deleting default route via 192.168.1.1
Oct 24 19:47:39 volumio volumio[977]: info: Discovery: A device disappeared from network
Oct 24 19:47:39 volumio volumio[977]: info: Discovery: Device volumio disappeared from network
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: Associated with 52:ff:20:80:28:d0
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-CONNECTED - Connection to 52:ff:20:80:28:d0 completed [id=0 id_str=]
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Oct 24 19:47:39 volumio wpa_supplicant[860]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=RU
Oct 24 19:47:39 volumio kernel: ieee80211 phy0: brcmf_cfg80211_reg_notifier: Firmware rejected country setting
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: carrier acquired
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: IAID 32:0e:79:4f
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: carrier lost
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: carrier acquired
Oct 24 19:47:39 volumio dhcpcd[872]: wlan0: IAID 32:0e:79:4f
Oct 24 19:47:40 volumio dhcpcd[872]: wlan0: soliciting an IPv6 router
Oct 24 19:47:40 volumio dhcpcd[872]: wlan0: rebinding lease of 192.168.1.35
Oct 24 19:47:41 volumio dhcpcd[872]: wlan0: probing address 192.168.1.35/24
Oct 24 19:47:41 volumio ntpd[759]: Deleting interface #17 wlan0, 192.168.1.35#123, interface stats: received=23, sent=33, dropped=1, active_time=10 secs
Oct 24 19:47:41 volumio ntpd[759]: 141.144.230.32 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 217.160.19.219 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 141.144.246.224 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 185.41.106.152 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 139.162.187.236 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 188.174.253.188 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 144.76.139.8 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 217.154.242.106 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 188.68.34.173 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 151.22.209.90 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 77.37.65.181 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 129.152.16.145 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 94.16.122.152 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 93.94.88.51 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 89.46.74.148 local addr 192.168.1.35 -> 
Oct 24 19:47:41 volumio ntpd[759]: 80.60.67.39 local addr 192.168.1.35 -> 
Oct 24 19:47:45 volumio dhcpcd[872]: wlan0: leased 192.168.1.35 for 25200 seconds
Oct 24 19:47:45 volumio avahi-daemon[607]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.35.
Oct 24 19:47:45 volumio avahi-daemon[607]: New relevant interface wlan0.IPv4 for mDNS.
Oct 24 19:47:45 volumio dhcpcd[872]: wlan0: adding route to 192.168.1.0/24
Oct 24 19:47:45 volumio dhcpcd[872]: wlan0: adding default route via 192.168.1.1
Oct 24 19:47:45 volumio avahi-daemon[607]: Registering new address record for 192.168.1.35 on wlan0.IPv4.
Oct 24 19:47:46 volumio volumio[977]: verbose: New Socket.io Connection to 192.168.1.35 from 192.168.1.2 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 YaBrowser/25.8.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Oct 24 19:47:46 volumio volumio[977]: info: Received Get System Info
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 24 19:47:46 volumio volumio[977]: info: Discovery: Getting this device information
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:47:46 volumio volumio[977]: info: Listing playlists
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::volumioGetQueue
Oct 24 19:47:46 volumio volumio[977]: info: CoreStateMachine::getQueue
Oct 24 19:47:46 volumio volumio[977]: info: CorePlayQueue::getQueue
Oct 24 19:47:46 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Oct 24 19:47:47 volumio ntpd[759]: Listen normally on 18 wlan0 192.168.1.35:123
Oct 24 19:47:47 volumio ntpd[759]: new interface(s) found: waking up resolver
Oct 24 19:47:48 volumio volumio[977]: info: Discovery: adding 1b7efee1-ab32-414f-bc94-56e1d0d385ab
Oct 24 19:47:48 volumio volumio[977]: info: Discovery: Found device Volumio
Oct 24 19:47:48 volumio volumio[977]: info: CoreCommandRouter::volumioGetState
Oct 24 19:47:49 volumio volumio[977]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 24 19:47:49 volumio volumio[977]: Error: read ECONNRESET
Oct 24 19:47:49 volumio volumio[977]:     at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) {
Oct 24 19:47:49 volumio volumio[977]:   errno: -104,
Oct 24 19:47:49 volumio volumio[977]:   code: 'ECONNRESET',
Oct 24 19:47:49 volumio volumio[977]:   syscall: 'read'
Oct 24 19:47:49 volumio volumio[977]: }
Oct 24 19:47:49 volumio volumio[977]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 24 19:47:50 volumio sudo[7758]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-24 19:46
Oct 24 19:47:50 volumio sudo[7758]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST"
VOLUMIO_VERSION="3.832"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"