-- Logs begin at Fri 2023-10-20 17:59:51 EEST, end at Fri 2023-10-20 19:01:43 EEST. -- Oct 20 19:00:02 primo ntpd[9802]: Soliciting pool server 2001:67c:440:688:91:236:251:143 Oct 20 19:00:04 primo ntpd[9802]: Soliciting pool server 62.149.0.30 Oct 20 19:00:06 primo ntpd[9802]: Soliciting pool server 91.236.251.31 Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.287613, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 20 19:00:16 primo nmbd[5138]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.287871, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Oct 20 19:00:16 primo nmbd[5138]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288020, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 20 19:00:16 primo nmbd[5138]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288146, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Oct 20 19:00:16 primo nmbd[5138]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288304, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 20 19:00:16 primo nmbd[5138]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288426, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Oct 20 19:00:16 primo nmbd[5138]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288554, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 20 19:00:16 primo nmbd[5138]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288672, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Oct 20 19:00:16 primo nmbd[5138]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288798, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 20 19:00:16 primo nmbd[5138]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Oct 20 19:00:16 primo nmbd[5138]: [2023/10/20 19:00:16.288918, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Oct 20 19:00:16 primo nmbd[5138]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Oct 20 19:01:00 primo nmbd[5138]: [2023/10/20 19:01:00.358129, 0] ../source3/libsmb/nmblib.c:917(send_udp) Oct 20 19:01:00 primo nmbd[5138]: Packet send failed to 192.168.211.255(138) ERRNO=Network is unreachable Oct 20 19:01:04 primo ntpd[9802]: Soliciting pool server 91.198.10.4 Oct 20 19:01:09 primo ntpd[9802]: Soliciting pool server 2001:67c:440:401:91:236:251:13 Oct 20 19:01:10 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:10 primo kernel: spdif_a is set to disable Oct 20 19:01:10 primo dhcpcd[6025]: eth0: carrier lost Oct 20 19:01:10 primo dhcpcd[5980]: eth0: carrier lost Oct 20 19:01:10 primo kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Down Oct 20 19:01:10 primo avahi-daemon[4501]: Withdrawing address record for 192.168.31.117 on eth0. Oct 20 19:01:10 primo avahi-daemon[4501]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.31.117. Oct 20 19:01:10 primo dhcpcd[6025]: eth0: deleting route to 192.168.31.0/24 Oct 20 19:01:10 primo avahi-daemon[4501]: Interface eth0.IPv4 no longer relevant for mDNS. Oct 20 19:01:10 primo dhcpcd[6025]: eth0: deleting default route via 192.168.31.1 Oct 20 19:01:10 primo volumio[5450]: info: Discovery: A device disappeared from network Oct 20 19:01:10 primo volumio[5450]: info: Discovery: Device primo disappeared from network Oct 20 19:01:10 primo dhcpcd[5980]: eth0: deleting route to 192.168.31.0/24 Oct 20 19:01:10 primo dhcpcd[5980]: eth0: deleting default route via 192.168.31.1 Oct 20 19:01:10 primo ifplugd(eth0)[5211]: Link beat lost. Oct 20 19:01:11 primo ntpd[9802]: Soliciting pool server 78.30.254.80 Oct 20 19:01:11 primo ntpd[9802]: Deleting interface #3 eth0, 192.168.31.117#123, interface stats: received=0, sent=54, dropped=0, active_time=992 secs Oct 20 19:01:13 primo ntpd[9802]: Soliciting pool server 91.210.190.13 Oct 20 19:01:14 primo dhcpcd[6025]: eth0: carrier acquired Oct 20 19:01:14 primo dhcpcd[5980]: eth0: carrier acquired Oct 20 19:01:14 primo kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Oct 20 19:01:14 primo dhcpcd[6025]: eth0: IAID 00:2e:20:01 Oct 20 19:01:14 primo dhcpcd[5980]: eth0: IAID 00:2e:20:01 Oct 20 19:01:14 primo dhcpcd[5980]: eth0: soliciting an IPv6 router Oct 20 19:01:14 primo dhcpcd[6025]: eth0: rebinding lease of 192.168.31.117 Oct 20 19:01:15 primo ifplugd(eth0)[5211]: Link beat detected. Oct 20 19:01:15 primo dhcpcd[6025]: eth0: probing address 192.168.31.117/24 Oct 20 19:01:15 primo dhcpcd[6025]: eth0: soliciting an IPv6 router Oct 20 19:01:15 primo dhcpcd[5980]: eth0: rebinding lease of 192.168.31.117 Oct 20 19:01:16 primo dhcpcd[5980]: eth0: probing address 192.168.31.117/24 Oct 20 19:01:20 primo dhcpcd[6025]: eth0: leased 192.168.31.117 for 43200 seconds Oct 20 19:01:20 primo dhcpcd[6025]: eth0: adding route to 192.168.31.0/24 Oct 20 19:01:20 primo avahi-daemon[4501]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.31.117. Oct 20 19:01:20 primo dhcpcd[6025]: eth0: adding default route via 192.168.31.1 Oct 20 19:01:20 primo avahi-daemon[4501]: New relevant interface eth0.IPv4 for mDNS. Oct 20 19:01:20 primo avahi-daemon[4501]: Registering new address record for 192.168.31.117 on eth0.IPv4. Oct 20 19:01:20 primo shairport-sync[8715]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Oct 20 19:01:20 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:20 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:20 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:20 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:20 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:20 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:20 primo kernel: spdif_a is set to enable Oct 20 19:01:20 primo ntpd[9802]: ntpd exiting on signal 15 (Terminated) Oct 20 19:01:20 primo systemd[1]: Stopping Network Time Service... Oct 20 19:01:20 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:20 primo systemd[1]: ntp.service: Succeeded. Oct 20 19:01:20 primo systemd[1]: Stopped Network Time Service. Oct 20 19:01:20 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 20 19:01:20 primo systemd[1]: Starting Network Time Service... Oct 20 19:01:20 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:21 primo ntpd[10008]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 20 19:01:21 primo ntpd[10008]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 20 19:01:21 primo systemd[1]: Started Network Time Service. Oct 20 19:01:21 primo ntpd[10044]: proto: precision = 1.208 usec (-20) Oct 20 19:01:21 primo ntpd[10044]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 20 19:01:21 primo ntpd[10044]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 20 19:01:21 primo ntpd[10044]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 297 days ago Oct 20 19:01:21 primo ntpd[10044]: Listen and drop on 0 v6wildcard [::]:123 Oct 20 19:01:21 primo ntpd[10044]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 20 19:01:21 primo ntpd[10044]: Listen normally on 2 lo 127.0.0.1:123 Oct 20 19:01:21 primo ntpd[10044]: Listen normally on 3 eth0 192.168.31.117:123 Oct 20 19:01:21 primo ntpd[10044]: Listen normally on 4 wlan0 192.168.31.205:123 Oct 20 19:01:21 primo ntpd[10044]: Listening on routing socket on fd #21 for interface updates Oct 20 19:01:21 primo ntpd[10044]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:21 primo ntpd[10044]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:21 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:21 primo kernel: spdif_a is set to disable Oct 20 19:01:21 primo volumio[5450]: info: Discovery: adding undefined Oct 20 19:01:21 primo volumio[5450]: info: Discovery: Found device Primo Oct 20 19:01:21 primo volumio[5450]: info: CoreCommandRouter::volumioGetState Oct 20 19:01:21 primo dhcpcd[5980]: eth0: leased 192.168.31.117 for 43200 seconds Oct 20 19:01:21 primo dhcpcd[5980]: eth0: adding route to 192.168.31.0/24 Oct 20 19:01:21 primo dhcpcd[5980]: eth0: adding default route via 192.168.31.1 Oct 20 19:01:22 primo ntpd[10044]: ntpd exiting on signal 15 (Terminated) Oct 20 19:01:22 primo systemd[1]: Stopping Network Time Service... Oct 20 19:01:22 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:22 primo systemd[1]: ntp.service: Succeeded. Oct 20 19:01:22 primo systemd[1]: Stopped Network Time Service. Oct 20 19:01:22 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 20 19:01:22 primo systemd[1]: Starting Network Time Service... Oct 20 19:01:22 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:22 primo ntpd[10097]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 20 19:01:22 primo ntpd[10097]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 20 19:01:22 primo systemd[1]: Started Network Time Service. Oct 20 19:01:22 primo ntpd[10123]: proto: precision = 1.209 usec (-20) Oct 20 19:01:22 primo ntpd[10123]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 20 19:01:22 primo ntpd[10123]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 20 19:01:22 primo ntpd[10123]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 297 days ago Oct 20 19:01:22 primo ntpd[10123]: Listen and drop on 0 v6wildcard [::]:123 Oct 20 19:01:22 primo ntpd[10123]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 20 19:01:22 primo ntpd[10123]: Listen normally on 2 lo 127.0.0.1:123 Oct 20 19:01:22 primo ntpd[10123]: Listen normally on 3 eth0 192.168.31.117:123 Oct 20 19:01:22 primo ntpd[10123]: Listen normally on 4 wlan0 192.168.31.205:123 Oct 20 19:01:22 primo ntpd[10123]: Listening on routing socket on fd #21 for interface updates Oct 20 19:01:22 primo ntpd[10123]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:22 primo ntpd[10123]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:22 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:22 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:22 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:22 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:22 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:22 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:22 primo kernel: spdif_a is set to enable Oct 20 19:01:22 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:22 primo kernel: spdif_a is set to disable Oct 20 19:01:22 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:22 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:22 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:22 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:22 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:22 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:22 primo kernel: spdif_a is set to enable Oct 20 19:01:22 primo shairport-sync[8715]: Very large sync error: 4294966947 frames, with delay: 4295055147, td_in_frames: 50296, rt: 9756485958, nt: 5461487245, current_delay: 6138, seqno: 52781, given timestamp: 1166519949. Oct 20 19:01:22 primo shairport-sync[8715]: Very large sync error: 4294966919 frames, with delay: 4295055119, td_in_frames: 50781, rt: 9756485958, nt: 5461487597, current_delay: 5977, seqno: 52782, given timestamp: 1166520301. Oct 20 19:01:22 primo shairport-sync[8715]: Very large sync error: 4294966917 frames, with delay: 4295055117, td_in_frames: 51292, rt: 9756485958, nt: 5461487949, current_delay: 5816, seqno: 52783, given timestamp: 1166520653. Oct 20 19:01:22 primo shairport-sync[8715]: Very large sync error: 4294966925 frames, with delay: 4295055125, td_in_frames: 51301, rt: 9756485958, nt: 5461488301, current_delay: 6167, seqno: 52784, given timestamp: 1166521005. Oct 20 19:01:22 primo shairport-sync[8715]: Shome mhistake shurely: very large number of frames to drop: 4294966925 -- setting it to 4295099596. Oct 20 19:01:22 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:22 primo kernel: spdif_a is set to disable Oct 20 19:01:23 primo ntpd[10123]: Soliciting pool server 217.12.206.12 Oct 20 19:01:24 primo ntpd[10123]: Soliciting pool server 193.106.144.13 Oct 20 19:01:25 primo ntpd[10123]: Soliciting pool server 193.106.144.6 Oct 20 19:01:25 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:25 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:25 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:25 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:25 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:25 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:25 primo kernel: spdif_a is set to enable Oct 20 19:01:26 primo ntpd[10123]: Soliciting pool server 193.106.144.13 Oct 20 19:01:30 primo dhcpcd[5980]: eth0: carrier lost Oct 20 19:01:30 primo dhcpcd[6025]: eth0: carrier lost Oct 20 19:01:30 primo kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Down Oct 20 19:01:30 primo avahi-daemon[4501]: Withdrawing address record for 192.168.31.117 on eth0. Oct 20 19:01:30 primo avahi-daemon[4501]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.31.117. Oct 20 19:01:30 primo avahi-daemon[4501]: Interface eth0.IPv4 no longer relevant for mDNS. Oct 20 19:01:30 primo volumio[5450]: info: Discovery: A device disappeared from network Oct 20 19:01:30 primo volumio[5450]: info: Discovery: Device primo disappeared from network Oct 20 19:01:30 primo dhcpcd[5980]: eth0: deleting route to 192.168.31.0/24 Oct 20 19:01:30 primo dhcpcd[6025]: eth0: deleting route to 192.168.31.0/24 Oct 20 19:01:30 primo dhcpcd[6025]: eth0: deleting default route via 192.168.31.1 Oct 20 19:01:30 primo dhcpcd[5980]: eth0: deleting default route via 192.168.31.1 Oct 20 19:01:30 primo ifplugd(eth0)[5211]: Link beat lost. Oct 20 19:01:30 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:30 primo kernel: spdif_a is set to disable Oct 20 19:01:31 primo ntpd[10123]: Deleting interface #3 eth0, 192.168.31.117#123, interface stats: received=0, sent=4, dropped=0, active_time=9 secs Oct 20 19:01:35 primo dhcpcd[6025]: eth0: carrier acquired Oct 20 19:01:35 primo dhcpcd[5980]: eth0: carrier acquired Oct 20 19:01:35 primo kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Oct 20 19:01:35 primo dhcpcd[6025]: eth0: IAID 00:2e:20:01 Oct 20 19:01:35 primo dhcpcd[5980]: eth0: IAID 00:2e:20:01 Oct 20 19:01:35 primo ifplugd(eth0)[5211]: Link beat detected. Oct 20 19:01:35 primo dhcpcd[6025]: eth0: rebinding lease of 192.168.31.117 Oct 20 19:01:35 primo dhcpcd[6025]: eth0: soliciting an IPv6 router Oct 20 19:01:35 primo dhcpcd[6025]: eth0: probing address 192.168.31.117/24 Oct 20 19:01:35 primo dhcpcd[5980]: eth0: soliciting an IPv6 router Oct 20 19:01:35 primo dhcpcd[5980]: eth0: rebinding lease of 192.168.31.117 Oct 20 19:01:36 primo dhcpcd[5980]: eth0: probing address 192.168.31.117/24 Oct 20 19:01:40 primo dhcpcd[6025]: eth0: leased 192.168.31.117 for 43200 seconds Oct 20 19:01:40 primo dhcpcd[6025]: eth0: adding route to 192.168.31.0/24 Oct 20 19:01:40 primo avahi-daemon[4501]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.31.117. Oct 20 19:01:40 primo dhcpcd[6025]: eth0: adding default route via 192.168.31.1 Oct 20 19:01:40 primo avahi-daemon[4501]: New relevant interface eth0.IPv4 for mDNS. Oct 20 19:01:40 primo avahi-daemon[4501]: Registering new address record for 192.168.31.117 on eth0.IPv4. Oct 20 19:01:40 primo shairport-sync[8715]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Oct 20 19:01:40 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:40 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:40 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:40 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:40 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:40 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:40 primo kernel: spdif_a is set to enable Oct 20 19:01:40 primo ntpd[10123]: ntpd exiting on signal 15 (Terminated) Oct 20 19:01:40 primo systemd[1]: Stopping Network Time Service... Oct 20 19:01:40 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:41 primo systemd[1]: ntp.service: Succeeded. Oct 20 19:01:41 primo systemd[1]: Stopped Network Time Service. Oct 20 19:01:41 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 20 19:01:41 primo systemd[1]: Starting Network Time Service... Oct 20 19:01:41 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:41 primo ntpd[10251]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 20 19:01:41 primo ntpd[10251]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 20 19:01:41 primo systemd[1]: Started Network Time Service. Oct 20 19:01:41 primo ntpd[10287]: proto: precision = 1.208 usec (-20) Oct 20 19:01:41 primo ntpd[10287]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 20 19:01:41 primo ntpd[10287]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 20 19:01:41 primo ntpd[10287]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 297 days ago Oct 20 19:01:41 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:41 primo kernel: spdif_a is set to disable Oct 20 19:01:41 primo ntpd[10287]: Listen and drop on 0 v6wildcard [::]:123 Oct 20 19:01:41 primo ntpd[10287]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 20 19:01:41 primo ntpd[10287]: Listen normally on 2 lo 127.0.0.1:123 Oct 20 19:01:41 primo ntpd[10287]: Listen normally on 3 eth0 192.168.31.117:123 Oct 20 19:01:41 primo ntpd[10287]: Listen normally on 4 wlan0 192.168.31.205:123 Oct 20 19:01:41 primo ntpd[10287]: Listening on routing socket on fd #21 for interface updates Oct 20 19:01:41 primo ntpd[10287]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:41 primo ntpd[10287]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:41 primo dhcpcd[5980]: eth0: leased 192.168.31.117 for 43200 seconds Oct 20 19:01:41 primo dhcpcd[5980]: eth0: adding route to 192.168.31.0/24 Oct 20 19:01:41 primo dhcpcd[5980]: eth0: adding default route via 192.168.31.1 Oct 20 19:01:41 primo ntpd[10287]: ntpd exiting on signal 15 (Terminated) Oct 20 19:01:41 primo systemd[1]: Stopping Network Time Service... Oct 20 19:01:41 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:41 primo systemd[1]: ntp.service: Succeeded. Oct 20 19:01:41 primo systemd[1]: Stopped Network Time Service. Oct 20 19:01:41 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 20 19:01:41 primo systemd[1]: Starting Network Time Service... Oct 20 19:01:41 primo volumio[5450]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 19:01:41 primo ntpd[10340]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 20 19:01:41 primo ntpd[10340]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 20 19:01:41 primo systemd[1]: Started Network Time Service. Oct 20 19:01:41 primo ntpd[10366]: proto: precision = 1.250 usec (-20) Oct 20 19:01:41 primo ntpd[10366]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 20 19:01:41 primo ntpd[10366]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 20 19:01:41 primo ntpd[10366]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 297 days ago Oct 20 19:01:41 primo ntpd[10366]: Listen and drop on 0 v6wildcard [::]:123 Oct 20 19:01:41 primo ntpd[10366]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 20 19:01:41 primo ntpd[10366]: Listen normally on 2 lo 127.0.0.1:123 Oct 20 19:01:41 primo ntpd[10366]: Listen normally on 3 eth0 192.168.31.117:123 Oct 20 19:01:41 primo ntpd[10366]: Listen normally on 4 wlan0 192.168.31.205:123 Oct 20 19:01:41 primo ntpd[10366]: Listening on routing socket on fd #21 for interface updates Oct 20 19:01:41 primo ntpd[10366]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:41 primo ntpd[10366]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 20 19:01:41 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:41 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:41 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:41 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:41 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:41 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:41 primo kernel: spdif_a is set to enable Oct 20 19:01:41 primo volumio[5450]: info: Discovery: adding undefined Oct 20 19:01:41 primo volumio[5450]: info: Discovery: Found device Primo Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::volumioGetState Oct 20 19:01:41 primo volumio[5450]: verbose: New Socket.io Connection to 192.168.31.117 from 192.168.31.143 UA: unknown Total Clients: 5 Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::volumioGetState Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 19:01:41 primo volumio[5450]: info: Discovery: Getting this device information Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::volumioGetState Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 20 19:01:41 primo volumio[5450]: info: Discovery: Getting this device information Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::volumioGetState Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 20 19:01:41 primo volumio[5450]: verbose: New Socket.io Connection to 192.168.31.205 from 192.168.31.143 UA: unknown Total Clients: 6 Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::volumioGetState Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 20 19:01:41 primo volumio[5450]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 20 19:01:41 primo kernel: asoc-aml-card auge_sound: tdm playback stop Oct 20 19:01:41 primo kernel: spdif_a is set to disable Oct 20 19:01:42 primo kernel: aml_tdm_prepare(), reset fddr Oct 20 19:01:42 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Oct 20 19:01:42 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 20 19:01:42 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 20 19:01:42 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 20 19:01:42 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 20 19:01:42 primo kernel: spdif_a is set to enable Oct 20 19:01:42 primo ntpd[10366]: Soliciting pool server 217.12.206.12 Oct 20 19:01:42 primo volumio[5450]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 20 19:01:42 primo volumio[5450]: Error: certificate is not yet valid Oct 20 19:01:42 primo volumio[5450]: at TLSSocket.onConnectSecure (_tls_wrap.js:1515:34) Oct 20 19:01:42 primo volumio[5450]: at TLSSocket.emit (events.js:400:28) Oct 20 19:01:42 primo volumio[5450]: at TLSSocket._finishInit (_tls_wrap.js:937:8) Oct 20 19:01:42 primo volumio[5450]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:709:12) { Oct 20 19:01:42 primo volumio[5450]: code: 'CERT_NOT_YET_VALID' Oct 20 19:01:42 primo volumio[5450]: } Oct 20 19:01:42 primo volumio[5450]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 20 19:01:43 primo sudo[10397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-10-20 19:00 Oct 20 19:01:43 primo sudo[10397]: 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="893d2e91c55a7857b58762e70c2f65b9d163562b" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="30b77d58bf3c2745acc494ddafed946392a79905" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 20 Oct 2023 04:59:51 PM CEST" VOLUMIO_VERSION="3.569" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="e98c6319e6885de78ea678359d2d3c00"