-- Logs begin at Sun 2024-07-07 16:44:34 CEST, end at Mon 2024-07-08 02:12:32 CEST. -- Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces system playlist update Jul 08 02:11:00 rivo volumio[18579]: info: Ignoring MPD Status Update Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:00 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:00 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:00 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:00 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:00 rivo volumio[18579]: info: ------------------------------ 3ms Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces system playlist update Jul 08 02:11:00 rivo volumio[18579]: info: Ignoring MPD Status Update Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:00 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:00 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces system playlist update Jul 08 02:11:00 rivo volumio[18579]: info: Ignoring MPD Status Update Jul 08 02:11:00 rivo volumio[18579]: info: Jul 08 02:11:00 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:00 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:00 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:00 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:00 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:00 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 02:11:00 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Jul 08 02:11:01 rivo kernel: spdif_a keep clk continuous Jul 08 02:11:01 rivo kernel: aml_spdif_close Jul 08 02:11:01 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jul 08 02:11:01 rivo kernel: aml_spdif_open Jul 08 02:11:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jul 08 02:11:01 rivo kernel: set normal 512 fs /4 fs Jul 08 02:11:01 rivo kernel: set spdifout clk:6144000, mpll:24576000 Jul 08 02:11:01 rivo kernel: get spdifout clk:6143997, mpll:24575987 Jul 08 02:11:01 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jul 08 02:11:01 rivo kernel: set normal 512 fs /4 fs Jul 08 02:11:01 rivo kernel: set spdifout clk:6144000, mpll:24576000 Jul 08 02:11:01 rivo kernel: get spdifout clk:6143997, mpll:24575987 Jul 08 02:11:01 rivo kernel: spdif_info: rate: 48000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x200, ch1_r:0x200 Jul 08 02:11:01 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Jul 08 02:11:01 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 1004 milliseconds Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: info: Jul 08 02:11:01 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 1005 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 1004ms Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 1003 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 1004ms Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 1002 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseTrackInfo Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 1020ms Jul 08 02:11:01 rivo volumio[18579]: info: Jul 08 02:11:01 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:01 rivo volumio[18579]: info: Jul 08 02:11:01 rivo volumio[18579]: ---------------------------- MPD announces state update: player Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::getState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand status Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 20 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 18 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 19 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 18 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 8 milliseconds Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseTrackInfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseTrackInfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":860,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 1050ms Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 1049ms Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 1048ms Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand status took 41 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 35 milliseconds Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 34 milliseconds Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseState Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseTrackInfo Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 78ms Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 63ms Jul 08 02:11:01 rivo volumio[18579]: info: sendMpdCommand playlistinfo took 20 milliseconds Jul 08 02:11:01 rivo volumio[18579]: verbose: ControllerMpd::parseTrackInfo Jul 08 02:11:01 rivo volumio[18579]: info: ControllerMpd::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::servicePushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":600,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2304 Kbps","isStreaming":false,"title":"1 - Pink Noise 48kHz.flac","artist":null,"album":null,"uri":"USB/DEFC-640A/Burn in noises/1 - Pink Noise 48kHz.flac","trackType":"flac"} Jul 08 02:11:01 rivo volumio[18579]: verbose: CURRENT POSITION 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState stateService play Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::syncState currentStatus play Jul 08 02:11:01 rivo volumio[18579]: info: Received an update from plugin. extracting info from payload Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: CoreStateMachine::pushState Jul 08 02:11:01 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:11:01 rivo volumio[18579]: info: CoreCommandRouter::volumioPushState Jul 08 02:11:01 rivo volumio[18579]: info: ------------------------------ 72ms Jul 08 02:11:31 rivo ntpd[18349]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jul 08 02:11:43 rivo ntpd[18349]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jul 08 02:11:44 rivo ntpd[18349]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jul 08 02:11:46 rivo ntpd[18349]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jul 08 02:12:17 rivo wpa_supplicant[7019]: wlan0: Trying to associate with da:f6:e3:ed:bc:2a (SSID='Volumio-47FCO' freq=2437 MHz) Jul 08 02:12:17 rivo kernel: Connecting with da:f6:e3:ed:bc:2a ssid "Volumio-47FCO", len (13) channel=6 Jul 08 02:12:17 rivo kernel: dhd_dbg_start_pkt_monitor, 1724 Jul 08 02:12:17 rivo kernel: wl_iw_event: Link UP with da:f6:e3:ed:bc:2a Jul 08 02:12:17 rivo kernel: wl_bss_connect_done succeeded with da:f6:e3:ed:bc:2a Jul 08 02:12:17 rivo kernel: CFG80211-ERROR) wl_cfg80211_scan_abort : scan abort failed Jul 08 02:12:17 rivo wpa_supplicant[7019]: wlan0: Associated with da:f6:e3:ed:bc:2a Jul 08 02:12:17 rivo wpa_supplicant[7019]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 08 02:12:17 rivo kernel: wl_bss_connect_done succeeded with da:f6:e3:ed:bc:2a vndr_oui: 8C-FD-F0 Jul 08 02:12:17 rivo wpa_supplicant[7019]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=IT Jul 08 02:12:17 rivo wpa_supplicant[7019]: wlan0: WPA: Key negotiation completed with da:f6:e3:ed:bc:2a [PTK=CCMP GTK=CCMP] Jul 08 02:12:17 rivo wpa_supplicant[7019]: wlan0: CTRL-EVENT-CONNECTED - Connection to da:f6:e3:ed:bc:2a completed [id=0 id_str=] Jul 08 02:12:17 rivo dhcpcd[3367]: wlan0: carrier acquired Jul 08 02:12:17 rivo dhcpcd[3367]: wlan0: IAID 28:29:82:a4 Jul 08 02:12:17 rivo dhcpcd[3367]: wlan0: soliciting a DHCP lease Jul 08 02:12:17 rivo dhcpcd[3367]: wlan0: probing address 192.168.211.92/24 Jul 08 02:12:18 rivo dhcpcd[3367]: wlan0: soliciting an IPv6 router Jul 08 02:12:23 rivo dhcpcd[3367]: wlan0: leased 192.168.211.92 for 3599 seconds Jul 08 02:12:23 rivo avahi-daemon[2844]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.92. Jul 08 02:12:23 rivo avahi-daemon[2844]: New relevant interface wlan0.IPv4 for mDNS. Jul 08 02:12:23 rivo avahi-daemon[2844]: Registering new address record for 192.168.211.92 on wlan0.IPv4. Jul 08 02:12:23 rivo dhcpcd[3367]: wlan0: adding route to 192.168.211.0/24 Jul 08 02:12:23 rivo dhcpcd[3367]: wlan0: adding default route via 192.168.211.181 Jul 08 02:12:23 rivo ntpd[18349]: ntpd exiting on signal 15 (Terminated) Jul 08 02:12:23 rivo systemd[1]: Stopping Network Time Service... Jul 08 02:12:23 rivo systemd[1]: ntp.service: Succeeded. Jul 08 02:12:23 rivo systemd[1]: Stopped Network Time Service. Jul 08 02:12:23 rivo systemd[1]: Starting Network Time Service... Jul 08 02:12:23 rivo ntpd[28030]: ntpd 4.2.8p12@1.3728-o (1): Starting Jul 08 02:12:23 rivo ntpd[28030]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Jul 08 02:12:23 rivo systemd[1]: Started Network Time Service. Jul 08 02:12:23 rivo ntpd[28046]: proto: precision = 1.250 usec (-20) Jul 08 02:12:23 rivo ntpd[28046]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jul 08 02:12:23 rivo ntpd[28046]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jul 08 02:12:23 rivo ntpd[28046]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 559 days ago Jul 08 02:12:23 rivo ntpd[28046]: Listen and drop on 0 v6wildcard [::]:123 Jul 08 02:12:23 rivo ntpd[28046]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jul 08 02:12:23 rivo ntpd[28046]: Listen normally on 2 lo 127.0.0.1:123 Jul 08 02:12:23 rivo ntpd[28046]: Listen normally on 3 wlan0 192.168.211.92:123 Jul 08 02:12:23 rivo ntpd[28046]: Listening on routing socket on fd #20 for interface updates Jul 08 02:12:23 rivo ntpd[28046]: kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized Jul 08 02:12:23 rivo ntpd[28046]: kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized Jul 08 02:12:24 rivo volumio[18579]: info: Discovery: adding 8eebe7c4-458f-441a-ac73-c79348318dfd Jul 08 02:12:24 rivo volumio[18579]: info: Discovery: Found device Rivo Jul 08 02:12:24 rivo volumio[18579]: info: CoreCommandRouter::volumioGetState Jul 08 02:12:24 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:12:24 rivo ntpd[28046]: Soliciting pool server 212.45.144.206 Jul 08 02:12:25 rivo ntpd[28046]: Soliciting pool server 93.94.88.51 Jul 08 02:12:25 rivo ntpd[28046]: Soliciting pool server 212.45.144.3 Jul 08 02:12:26 rivo ntpd[28046]: Soliciting pool server 80.211.133.9 Jul 08 02:12:26 rivo ntpd[28046]: Soliciting pool server 85.199.214.99 Jul 08 02:12:26 rivo ntpd[28046]: Soliciting pool server 212.6.50.243 Jul 08 02:12:27 rivo ntpd[28046]: Soliciting pool server 217.61.62.224 Jul 08 02:12:27 rivo ntpd[28046]: Soliciting pool server 31.14.133.122 Jul 08 02:12:27 rivo ntpd[28046]: Soliciting pool server 95.230.240.5 Jul 08 02:12:27 rivo ntpd[28046]: Soliciting pool server 212.45.144.88 Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jul 08 02:12:27 rivo volumio[18579]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jul 08 02:12:28 rivo ntpd[28046]: Soliciting pool server 185.19.184.35 Jul 08 02:12:28 rivo ntpd[28046]: Soliciting pool server 185.157.229.254 Jul 08 02:12:28 rivo ntpd[28046]: Soliciting pool server 93.94.88.50 Jul 08 02:12:28 rivo volumio[18579]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jul 08 02:12:28 rivo volumio[18579]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jul 08 02:12:28 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 08 02:12:28 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 08 02:12:28 rivo volumio[18579]: info: Starting MyVolumio Remote Streaming Endpoints Jul 08 02:12:29 rivo volumio[18579]: info: MyVolumio login type: Token Jul 08 02:12:29 rivo volumio[18579]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jul 08 02:12:29 rivo volumio[18579]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Jul 08 02:12:29 rivo sudo[28051]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 08 02:12:29 rivo sudo[28051]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 02:12:29 rivo sudo[28051]: pam_unix(sudo:session): session closed for user root Jul 08 02:12:29 rivo sudo[28054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 08 02:12:29 rivo sudo[28054]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 02:12:29 rivo sudo[28054]: pam_unix(sudo:session): session closed for user root Jul 08 02:12:29 rivo volumio[18579]: verbose: New Socket.io Connection to 192.168.211.92 from 192.168.211.181 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jul 08 02:12:29 rivo volumio[18579]: error: MyVolumio Custom Token format not valid, refreshing it Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::volumioGetVisibleSources Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::volumioGetState Jul 08 02:12:29 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 08 02:12:29 rivo volumio[18579]: info: Received Get System Info Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 08 02:12:29 rivo volumio[18579]: info: Discovery: Getting this device information Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::volumioGetState Jul 08 02:12:29 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::volumioGetState Jul 08 02:12:29 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:12:29 rivo volumio[18579]: info: Listing playlists Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 08 02:12:29 rivo ntpd[28046]: Soliciting pool server 162.159.200.1 Jul 08 02:12:29 rivo ntpd[28046]: Soliciting pool server 95.110.254.234 Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 08 02:12:29 rivo volumio[18579]: info: Received Get System Info Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 08 02:12:29 rivo volumio[18579]: info: Discovery: Getting this device information Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::volumioGetState Jul 08 02:12:29 rivo volumio[18579]: info: CorePlayQueue::getTrack 0 Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 08 02:12:29 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 08 02:12:30 rivo ntpd[28046]: Soliciting pool server 95.242.98.72 Jul 08 02:12:30 rivo ntpd[28046]: Soliciting pool server 2606:4700:f1::1 Jul 08 02:12:30 rivo volumio[18579]: info: MyVolumio login type: Token Jul 08 02:12:31 rivo volumio[18579]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jul 08 02:12:31 rivo volumio[18579]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 08 02:12:32 rivo volumio[18579]: info: MyVolumio token set successfully Jul 08 02:12:32 rivo volumio[18579]: info: MYVOLUMIO: Adding device Jul 08 02:12:32 rivo volumio[18579]: info: MYVOLUMIO: Evaluating Server Jul 08 02:12:32 rivo volumio[18579]: info: MyVolumio status changed Jul 08 02:12:32 rivo volumio[18579]: info: Streaming services startup Jul 08 02:12:32 rivo volumio[18579]: info: Starting Streaming Daemon Jul 08 02:12:32 rivo volumio[18579]: info: Removing browser output: myVolumio user plan is not superstar Jul 08 02:12:32 rivo volumio[18579]: info: Removing audio output: Jul 08 02:12:32 rivo volumio[18579]: info: Stoppping Tunnel 1 Jul 08 02:12:32 rivo sudo[28077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 08 02:12:32 rivo sudo[28077]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 02:12:32 rivo sudo[28077]: pam_unix(sudo:session): session closed for user root Jul 08 02:12:32 rivo sudo[28081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jul 08 02:12:32 rivo sudo[28081]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 02:12:32 rivo volumio[18579]: error: Cannot start Volumio Streaming Daemon Jul 08 02:12:32 rivo volumio[18579]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 08 02:12:32 rivo volumio[18579]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 08 02:12:32 rivo sudo[28081]: pam_unix(sudo:session): session closed for user root Jul 08 02:12:32 rivo volumio[18579]: info: Remote SSH Stopped Jul 08 02:12:28 rivo volumio[18579]: error: Failed to ping endpoint us3.myvolumio.org : unknown error Jul 08 02:12:28 rivo volumio[18579]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 08 02:12:28 rivo ntpd[28046]: receive: Unexpected origin timestamp 0xea35ad70.c5948807 does not match aorg 0000000000.00000000 from server@31.14.133.122 xmt 0xea35ad6c.e5fea2cf Jul 08 02:12:28 rivo volumio[18579]: Error: Unable to resolve or reject the same promise twice Jul 08 02:12:28 rivo volumio[18579]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jul 08 02:12:28 rivo volumio[18579]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Jul 08 02:12:28 rivo volumio[18579]: at Socket.emit (events.js:412:35) Jul 08 02:12:28 rivo volumio[18579]: at endReadableNT (internal/streams/readable.js:1333:12) Jul 08 02:12:28 rivo volumio[18579]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jul 08 02:12:28 rivo volumio[18579]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 08 02:12:29 rivo sudo[28093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-08 02:11 Jul 08 02:12:29 rivo sudo[28093]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 09:27:25 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="891b8adfc94c7cc44424972b60e8e09c"