Problems with ntp and rtc

Post Reply
paulcrawford
Posts: 160
Joined: Tue May 10, 2016 11:51 am
languages_spoken: english
ODROIDs: c2 and n2
Has thanked: 19 times
Been thanked: 4 times
Contact:

Problems with ntp and rtc

Unread post by paulcrawford » Mon Sep 02, 2019 4:18 am

As noted in viewtopic.php?f=180&t=35465&p=262247&hilit=ntp#p262247 there are issues with using ntp with the n2 built in rtc.

In my case I installed ntp and then disabled it to ensure that the rtc worked.

This had been fine until a couple of days ago my n2 stopped running my datacoll program, which is written in c.

When I ran dmesg I got the following:

Code: Select all

[273534.046974] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
[273537.022842] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=04
[273537.534826] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
[273538.046785] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
[273541.022657] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=08
[273541.534623] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
[273542.046594] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
[273545.022457] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=12
I also found this in the syslog:

Code: Select all

Aug 30 22:00:35 no datacoll[27665]: hwclock: ioctl(RTC_RD_TIME) to /dev/rtc0 to read the time failed: Input/output error
Aug 30 22:00:35 no kernel: [274588.650872@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
When I searched for the hwclock error, I found this:

https://github.com/raspberrypi/firmware/issues/1065

This issue description seems consistent with the kind of error I experienced although it is for a pcf8523 rather than the pcf8563 that the n2 has.

I have disabled i2c-3 to prevent the rtc from being read from or written to and started ntp to keep time on the n2. In the long term I want to have both running but it does not seem possible right now.

I am running my program again to see that there is nothing else that could have caused the stoppage. The previous run started at 2019-08-28 13:09:32 and was interuppted by the rtc failure at 2019-08-30 20:01:58, so about 2 days and 7 hours.

Can HK please verify that issues noted in the raspberry pi reference above are the same as with n2 or completely different? If they are the same can HK please fix the problem?

With regard to ntp preventing the rtc working correctly, is @mad_ady's suggestion of editing the ntp.service the definitive answer or will something else be done by HK?

User avatar
odroid
Site Admin
Posts: 32552
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID
Has thanked: 189 times
Been thanked: 352 times
Contact:

Re: Problems with ntp and rtc

Unread post by odroid » Tue Sep 03, 2019 3:07 pm

We will check how we can handle the RTC oscillator stop/start bit properly.

But we need to find an easy way to reproduce the issue.
Do you access the HW clock in your application(datacoll) software directly?

paulcrawford
Posts: 160
Joined: Tue May 10, 2016 11:51 am
languages_spoken: english
ODROIDs: c2 and n2
Has thanked: 19 times
Been thanked: 4 times
Contact:

Re: Problems with ntp and rtc

Unread post by paulcrawford » Tue Sep 03, 2019 7:48 pm

There is only one call to the rtc in datacoll:

Code: Select all

      if (system("hwclock -s") == -1)
      {
         fprintf(stderr,"\ncan't sync to hwclock\n");
      }
It is located in the initialization part of the code so is only called once at the beginning of execution.

Does the kernel make continuing calls to the rtc during normal operation?

Thanks.

User avatar
odroid
Site Admin
Posts: 32552
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID
Has thanked: 189 times
Been thanked: 352 times
Contact:

Re: Problems with ntp and rtc

Unread post by odroid » Wed Sep 04, 2019 8:30 am

I believe Ubuntu calls it only when the system starts and shutdown.
But we need to check whether any services/deamon has tried to access the HW RTC periodically or not.

BTW, is there any possibility of your datacoll application restarts randomly?

paulcrawford
Posts: 160
Joined: Tue May 10, 2016 11:51 am
languages_spoken: english
ODROIDs: c2 and n2
Has thanked: 19 times
Been thanked: 4 times
Contact:

Re: Problems with ntp and rtc

Unread post by paulcrawford » Wed Sep 04, 2019 11:09 am

datacoll is set up as a service with an automatic restart if it fails for any reason. A typical reason would be a MySQL error when datacoll writes to Mariadb. It is always possible to see that there has been a restart as one gpio input always switches from 0 to 1 at startup. When the error occurred on Friday night that resulted in the dmesg rtc error there was no evidence that there was a datacoll restart.

What did you make of the issue documented in the Rpi github reference? I am not that knowledgeable on the details but it certainly seemed that if there was a random error in the rtc, it was not properly dealt with by the kernel.

On the behavior of Ubuntu, my expectation was as you noted that there should only be a call to the rtc at startup and again at shutdown.

User avatar
odroid
Site Admin
Posts: 32552
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID
Has thanked: 189 times
Been thanked: 352 times
Contact:

Re: Problems with ntp and rtc

Unread post by odroid » Wed Sep 04, 2019 1:25 pm

The 32.768Khz oscillator must stop shortly when we the driver writes values to the RTC registers. Our RTC driver also has the same function too.
To avoid any coincidence against other services or background software, the RTC writing process must be blocked in that period and users might meet a similar kernel messages.
So it is very normal.

But one RPi user wanted to access the RTC with other software in parallel and they tried to make a workaround.
But the workaround patch was reverted due to some negative side effects.

BTW, we've run a few N2 boards over 100 hours to test the USB 3.0 stability.
But there was no such RTC errors in "dmesg" outputs. So I guess something could be wrong in your data-collecting software or other services.
Let's try to narrow down root causes.

paulcrawford
Posts: 160
Joined: Tue May 10, 2016 11:51 am
languages_spoken: english
ODROIDs: c2 and n2
Has thanked: 19 times
Been thanked: 4 times
Contact:

Re: Problems with ntp and rtc

Unread post by paulcrawford » Wed Sep 04, 2019 10:00 pm

I had a closer look at the syslog when the problem occurred.

It seems that there was a network error that was the root cause. See the listing below starting at "Aug 30 20:02:09"

Code: Select all

Aug 30 20:02:02 no datacoll[2394]: [10]: fe, [11]: 58, [12]: cc, [13]: ff, [14]: fe, [15]: ff, [16]: fe, [17]: ff, [18]: fe, [19]: 83, [20]: 49
Aug 30 20:02:02 no datacoll[2394]: duty0 changed
Aug 30 20:02:02 no datacoll[2394]: top of dbselect captestflags: 109
Aug 30 20:02:02 no datacoll[2394]: charging: 0 CSW: 0 firsttime 0
Aug 30 20:02:02 no datacoll[2394]: runcaptest from db: 1 captestrunning from flags: 1
Aug 30 20:02:02 no datacoll[2394]: ctr: 1 ptr: 0
Aug 30 20:02:02 no datacoll[2394]: it: 0 id: 0
Aug 30 20:02:02 no datacoll[2394]: inside set pwm captestflags: 109
Aug 30 20:02:02 no datacoll[2394]: btdata.c20cap: -8.0000 b1a.present: -0.4001
Aug 30 20:02:02 no datacoll[2394]: deltac: 0.0001
Aug 30 20:02:02 no datacoll[2394]: deltacr: 0.2436 lcstate: 2263676
Aug 30 20:02:02 no watchdog[2522]: still alive after 257559 interval(s)
Aug 30 20:02:03 no watchdog[2522]: still alive after 257560 interval(s)
Aug 30 20:02:03 no kernel: [267476.845862@0] meson6-dwmac ff3f0000.ethernet eth0: Link is Down
Aug 30 20:02:04 no watchdog[2522]: still alive after 257561 interval(s)
Aug 30 20:02:05 no kernel: [267478.569972@0] meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 38400 to 9600
Aug 30 20:02:05 no watchdog[2522]: still alive after 257562 interval(s)
Aug 30 20:02:05 no kernel: [267478.784576@0] meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 9600 to 38400
Aug 30 20:02:06 no watchdog[2522]: still alive after 257563 interval(s)
Aug 30 20:02:07 no watchdog[2522]: still alive after 257564 interval(s)
Aug 30 20:02:08 no watchdog[2522]: still alive after 257565 interval(s)
Aug 30 20:02:09 no watchdog[2522]: still alive after 257566 interval(s)
Aug 30 20:02:09 no NetworkManager[2220]: <info>  [1567209729.5596] device (eth0): state change: activated -> unavailable (reason 'carrier-changed', sys-iface-state: 'managed')
Aug 30 20:02:09 no NetworkManager[2220]: <info>  [1567209729.5953] dhcp4 (eth0): canceled DHCP transaction, DHCP client pid 2461
Aug 30 20:02:09 no NetworkManager[2220]: <info>  [1567209729.5955] dhcp4 (eth0): state changed bound -> done
Aug 30 20:02:09 no NetworkManager[2220]: <info>  [1567209729.6021] manager: NetworkManager state is now CONNECTED_SITE
Aug 30 20:02:09 no dbus-daemon[2207]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=2220 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Aug 30 20:02:09 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 30 20:02:09 no NetworkManager[2220]: <info>  [1567209729.6317] manager: NetworkManager state is now CONNECTED_LOCAL
Aug 30 20:02:09 no NetworkManager[2220]: <info>  [1567209729.6357] manager: NetworkManager state is now DISCONNECTED
Aug 30 20:02:09 no dbus-daemon[2207]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Aug 30 20:02:09 no systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 30 20:02:09 no nm-dispatcher: req:1 'connectivity-change': new request (2 scripts)
Aug 30 20:02:09 no nm-dispatcher: req:1 'connectivity-change': start running ordered scripts...
Aug 30 20:02:09 no nm-dispatcher: req:2 'down' [eth0]: new request (2 scripts)
Aug 30 20:02:09 no nm-dispatcher: req:2 'down' [eth0]: start running ordered scripts...
Aug 30 20:02:10 no watchdog[2522]: still alive after 257567 interval(s)
Aug 30 20:02:11 no watchdog[2522]: still alive after 257568 interval(s)
Aug 30 20:02:12 no watchdog[2522]: still alive after 257569 interval(s)
Aug 30 20:02:13 no watchdog[2522]: still alive after 257570 interval(s)
Aug 30 20:02:14 no watchdog[2522]: still alive after 257571 interval(s)
Aug 30 20:02:15 no watchdog[2522]: still alive after 257572 interval(s)
Aug 30 20:02:16 no watchdog[2522]: still alive after 257573 interval(s)
Aug 30 20:02:17 no watchdog[2522]: still alive after 257574 interval(s)
Aug 30 20:02:18 no watchdog[2522]: still alive after 257575 interval(s)
Aug 30 20:02:19 no watchdog[2522]: still alive after 257576 interval(s)
Aug 30 20:02:20 no watchdog[2522]: still alive after 257577 interval(s)
Aug 30 20:02:21 no kernel: [267494.316863@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=21
Aug 30 20:02:21 no watchdog[2522]: still alive after 257578 interval(s)
Aug 30 20:02:21 no kernel: [267494.828826@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:22 no kernel: [267495.340807@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:22 no watchdog[2522]: still alive after 257579 interval(s)
Aug 30 20:02:23 no watchdog[2522]: still alive after 257580 interval(s)
Aug 30 20:02:24 no kernel: [267497.324720@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=24
Aug 30 20:02:24 no watchdog[2522]: still alive after 257581 interval(s)
Aug 30 20:02:24 no kernel: [267497.836685@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:25 no kernel: [267498.348658@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:25 no watchdog[2522]: still alive after 257582 interval(s)
Aug 30 20:02:26 no watchdog[2522]: still alive after 257583 interval(s)
Aug 30 20:02:27 no watchdog[2522]: still alive after 257584 interval(s)
Aug 30 20:02:28 no kernel: [267501.324530@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=28
Aug 30 20:02:28 no watchdog[2522]: still alive after 257585 interval(s)
Aug 30 20:02:28 no kernel: [267501.836527@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:29 no kernel: [267502.348461@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:29 no watchdog[2522]: still alive after 257586 interval(s)
Aug 30 20:02:30 no watchdog[2522]: still alive after 257587 interval(s)
Aug 30 20:02:31 no watchdog[2522]: still alive after 257588 interval(s)
Aug 30 20:02:32 no kernel: [267505.324325@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=32
Aug 30 20:02:32 no kernel: [267505.836303@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:32 no watchdog[2522]: still alive after 257589 interval(s)
Aug 30 20:02:33 no kernel: [267506.348266@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:33 no watchdog[2522]: still alive after 257590 interval(s)
Aug 30 20:02:34 no watchdog[2522]: still alive after 257591 interval(s)
Aug 30 20:02:35 no watchdog[2522]: still alive after 257592 interval(s)
Aug 30 20:02:36 no kernel: [267509.324133@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=36
Aug 30 20:02:36 no kernel: [267509.836106@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:36 no watchdog[2522]: still alive after 257593 interval(s)
Aug 30 20:02:37 no kernel: [267510.348076@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:37 no watchdog[2522]: still alive after 257594 interval(s)
Aug 30 20:02:38 no watchdog[2522]: still alive after 257595 interval(s)
Aug 30 20:02:39 no watchdog[2522]: still alive after 257596 interval(s)
Aug 30 20:02:40 no kernel: [267513.323941@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=40
Aug 30 20:02:40 no kernel: [267513.835907@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:40 no watchdog[2522]: still alive after 257597 interval(s)
Aug 30 20:02:41 no kernel: [267514.347910@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:41 no watchdog[2522]: still alive after 257598 interval(s)
Aug 30 20:02:42 no watchdog[2522]: still alive after 257599 interval(s)
Aug 30 20:02:43 no watchdog[2522]: still alive after 257600 interval(s)
Aug 30 20:02:44 no kernel: [267517.323741@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=44
Aug 30 20:02:44 no kernel: [267517.803924@0] meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5059] device (eth0): carrier: link connected
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5076] device (eth0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5171] policy: auto-activating connection 'Wired connection 1'
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5304] device (eth0): Activation: starting connection 'Wired connection 1' (d19dbcdd-02e7-3a28-ad6c-c292c1033b0a)
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5340] device (eth0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5380] manager: NetworkManager state is now CONNECTING
Aug 30 20:02:44 no kernel: [267517.835788@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5435] device (eth0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5467] device (eth0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5492] dhcp4 (eth0): activation: beginning transaction (timeout in 45 seconds)
Aug 30 20:02:44 no NetworkManager[2220]: <info>  [1567209764.5549] dhcp4 (eth0): dhclient started with pid 27073
Aug 30 20:02:44 no dhclient[27073]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x2af0205c)
Aug 30 20:02:44 no watchdog[2522]: still alive after 257601 interval(s)
Aug 30 20:02:45 no kernel: [267518.347684@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:45 no watchdog[2522]: still alive after 257602 interval(s)
Aug 30 20:02:46 no watchdog[2522]: still alive after 257603 interval(s)
Aug 30 20:02:47 no dhclient[27073]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x2af0205c)
Aug 30 20:02:47 no watchdog[2522]: still alive after 257604 interval(s)
Aug 30 20:02:48 no kernel: [267521.323544@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=48
Aug 30 20:02:48 no kernel: [267521.835517@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:48 no watchdog[2522]: still alive after 257605 interval(s)
Aug 30 20:02:49 no kernel: [267522.347491@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:49 no watchdog[2522]: still alive after 257606 interval(s)
Aug 30 20:02:50 no watchdog[2522]: still alive after 257607 interval(s)
Aug 30 20:02:51 no watchdog[2522]: still alive after 257608 interval(s)
Aug 30 20:02:52 no kernel: [267525.323354@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=52
Aug 30 20:02:52 no kernel: [267525.835325@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:52 no watchdog[2522]: still alive after 257609 interval(s)
Aug 30 20:02:53 no dhclient[27073]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x2af0205c)
Aug 30 20:02:53 no kernel: [267526.347291@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:53 no watchdog[2522]: still alive after 257610 interval(s)
Aug 30 20:02:54 no watchdog[2522]: still alive after 257611 interval(s)
Aug 30 20:02:55 no watchdog[2522]: still alive after 257612 interval(s)
Aug 30 20:02:56 no kernel: [267529.323158@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=56
Aug 30 20:02:56 no kernel: [267529.835130@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:56 no watchdog[2522]: still alive after 257613 interval(s)
Aug 30 20:02:57 no kernel: [267530.347104@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:02:57 no watchdog[2522]: still alive after 257614 interval(s)
Aug 30 20:02:58 no watchdog[2522]: still alive after 257615 interval(s)
Aug 30 20:02:59 no watchdog[2522]: still alive after 257616 interval(s)
Aug 30 20:03:00 no kernel: [267533.322955@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=00
Aug 30 20:03:00 no kernel: [267533.834926@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:00 no watchdog[2522]: still alive after 257617 interval(s)
Aug 30 20:03:01 no kernel: [267534.346905@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:01 no watchdog[2522]: still alive after 257618 interval(s)
Aug 30 20:03:02 no watchdog[2522]: still alive after 257619 interval(s)
Aug 30 20:03:03 no watchdog[2522]: still alive after 257620 interval(s)
Aug 30 20:03:04 no kernel: [267537.322762@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=04
Aug 30 20:03:04 no kernel: [267537.834737@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:04 no watchdog[2522]: still alive after 257621 interval(s)
Aug 30 20:03:05 no kernel: [267538.346712@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:05 no watchdog[2522]: still alive after 257622 interval(s)
Aug 30 20:03:06 no watchdog[2522]: still alive after 257623 interval(s)
Aug 30 20:03:07 no dhclient[27073]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0xe4c5c97b)
Aug 30 20:03:07 no dhclient[27073]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x7bc9c5e4)
Aug 30 20:03:07 no dhclient[27073]: DHCPOFFER of 192.168.10.240 from 192.168.10.1
Aug 30 20:03:07 no dhclient[27073]: DHCPACK of 192.168.10.240 from 192.168.10.1
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0754] dhcp4 (eth0):   address 192.168.10.240
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0756] dhcp4 (eth0):   plen 24 (255.255.255.0)
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0757] dhcp4 (eth0):   gateway 192.168.10.1
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0758] dhcp4 (eth0):   lease time 1200
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0759] dhcp4 (eth0):   nameserver '192.168.10.1'
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0760] dhcp4 (eth0):   domain name 'cgocable.net'
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0763] dhcp4 (eth0): state changed unknown -> bound
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0833] device (eth0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0910] device (eth0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0947] device (eth0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.0970] manager: NetworkManager state is now CONNECTED_LOCAL
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.1029] manager: NetworkManager state is now CONNECTED_SITE
Aug 30 20:03:07 no dhclient[27073]: bound to 192.168.10.240 -- renewal in 548 seconds.
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.1041] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.1066] device (eth0): Activation: successful, device activated.
Aug 30 20:03:07 no dbus-daemon[2207]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=2220 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Aug 30 20:03:07 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 30 20:03:07 no NetworkManager[2220]: <info>  [1567209787.1101] manager: NetworkManager state is now CONNECTED_GLOBAL
Aug 30 20:03:07 no dbus-daemon[2207]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Aug 30 20:03:07 no systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 30 20:03:07 no nm-dispatcher: req:1 'up' [eth0]: new request (2 scripts)
Aug 30 20:03:07 no nm-dispatcher: req:1 'up' [eth0]: start running ordered scripts...
Aug 30 20:03:07 no nm-dispatcher: req:2 'connectivity-change': new request (2 scripts)
Aug 30 20:03:07 no systemd[1]: Reloading OpenBSD Secure Shell server.
Aug 30 20:03:07 no systemd-resolved[2198]: Using degraded feature set (UDP) for DNS server 192.168.10.1.
Aug 30 20:03:07 no systemd[1]: Reloaded OpenBSD Secure Shell server.
Aug 30 20:03:07 no systemd[1]: Reloading OpenBSD Secure Shell server.
Aug 30 20:03:07 no nm-dispatcher: req:2 'connectivity-change': start running ordered scripts...
Aug 30 20:03:07 no systemd[1]: Reloaded OpenBSD Secure Shell server.
Aug 30 20:03:07 no watchdog[2522]: still alive after 257624 interval(s)
Aug 30 20:03:08 no kernel: [267541.322583@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=08
Aug 30 20:03:08 no kernel: [267541.834548@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:09 no watchdog[2522]: still alive after 257625 interval(s)
Aug 30 20:03:09 no kernel: [267542.346514@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:10 no watchdog[2522]: still alive after 257626 interval(s)
Aug 30 20:03:11 no watchdog[2522]: still alive after 257627 interval(s)
Aug 30 20:03:12 no kernel: [267545.322403@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=12
Aug 30 20:03:12 no watchdog[2522]: still alive after 257628 interval(s)
Aug 30 20:03:12 no kernel: [267545.834374@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:13 no watchdog[2522]: still alive after 257629 interval(s)
Aug 30 20:03:13 no kernel: [267546.346349@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:14 no watchdog[2522]: still alive after 257630 interval(s)
Aug 30 20:03:15 no watchdog[2522]: still alive after 257631 interval(s)
Aug 30 20:03:16 no kernel: [267549.322180@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=16
Aug 30 20:03:16 no watchdog[2522]: still alive after 257632 interval(s)
Aug 30 20:03:16 no kernel: [267549.834146@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:17 no kernel: [267550.346121@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:17 no watchdog[2522]: still alive after 257633 interval(s)
Aug 30 20:03:18 no watchdog[2522]: still alive after 257634 interval(s)
Aug 30 20:03:19 no watchdog[2522]: still alive after 257635 interval(s)
Aug 30 20:03:20 no kernel: [267553.321980@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=20
Aug 30 20:03:20 no watchdog[2522]: still alive after 257636 interval(s)
Aug 30 20:03:20 no kernel: [267553.833957@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:21 no kernel: [267554.345933@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:21 no watchdog[2522]: still alive after 257637 interval(s)
Aug 30 20:03:22 no watchdog[2522]: still alive after 257638 interval(s)
Aug 30 20:03:23 no watchdog[2522]: still alive after 257639 interval(s)
Aug 30 20:03:24 no kernel: [267557.321791@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=24
Aug 30 20:03:24 no watchdog[2522]: still alive after 257640 interval(s)
Aug 30 20:03:24 no ntpdate[27095]: adjust time server 206.108.0.133 offset 0.000005 sec
Aug 30 20:03:24 no kernel: [267557.833760@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:25 no kernel: [267558.345731@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:25 no watchdog[2522]: still alive after 257641 interval(s)
Aug 30 20:03:26 no watchdog[2522]: still alive after 257642 interval(s)
Aug 30 20:03:27 no watchdog[2522]: still alive after 257643 interval(s)
Aug 30 20:03:28 no kernel: [267561.321591@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=28
Aug 30 20:03:28 no watchdog[2522]: still alive after 257644 interval(s)
Aug 30 20:03:28 no kernel: [267561.833556@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:29 no kernel: [267562.345531@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:29 no watchdog[2522]: still alive after 257645 interval(s)
Aug 30 20:03:30 no watchdog[2522]: still alive after 257646 interval(s)
Aug 30 20:03:31 no watchdog[2522]: still alive after 257647 interval(s)
Aug 30 20:03:32 no kernel: [267565.321393@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=32
Aug 30 20:03:32 no watchdog[2522]: still alive after 257648 interval(s)
Aug 30 20:03:32 no kernel: [267565.833354@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:33 no kernel: [267566.345333@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:33 no watchdog[2522]: still alive after 257649 interval(s)
Aug 30 20:03:34 no watchdog[2522]: still alive after 257650 interval(s)
Aug 30 20:03:35 no watchdog[2522]: still alive after 257651 interval(s)
Aug 30 20:03:36 no kernel: [267569.321189@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=36
Aug 30 20:03:36 no watchdog[2522]: still alive after 257652 interval(s)
Aug 30 20:03:36 no kernel: [267569.833168@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:37 no kernel: [267570.345136@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:37 no watchdog[2522]: still alive after 257653 interval(s)
Aug 30 20:03:38 no watchdog[2522]: still alive after 257654 interval(s)
Aug 30 20:03:39 no watchdog[2522]: still alive after 257655 interval(s)
Aug 30 20:03:40 no kernel: [267573.321001@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=40
Aug 30 20:03:40 no watchdog[2522]: still alive after 257656 interval(s)
Aug 30 20:03:40 no kernel: [267573.832972@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:41 no kernel: [267574.344941@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:41 no watchdog[2522]: still alive after 257657 interval(s)
Aug 30 20:03:42 no watchdog[2522]: still alive after 257658 interval(s)
Aug 30 20:03:43 no watchdog[2522]: still alive after 257659 interval(s)
Aug 30 20:03:44 no kernel: [267577.320812@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=44
Aug 30 20:03:44 no watchdog[2522]: still alive after 257660 interval(s)
Aug 30 20:03:44 no kernel: [267577.832778@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:45 no kernel: [267578.344751@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:45 no watchdog[2522]: still alive after 257661 interval(s)
Aug 30 20:03:46 no watchdog[2522]: still alive after 257662 interval(s)
Aug 30 20:03:47 no watchdog[2522]: still alive after 257663 interval(s)
Aug 30 20:03:48 no kernel: [267581.320603@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=48
Aug 30 20:03:48 no watchdog[2522]: still alive after 257664 interval(s)
Aug 30 20:03:48 no kernel: [267581.832576@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:49 no kernel: [267582.344545@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:50 no watchdog[2522]: still alive after 257665 interval(s)
Aug 30 20:03:51 no watchdog[2522]: still alive after 257666 interval(s)
Aug 30 20:03:52 no kernel: [267585.320408@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=52
Aug 30 20:03:52 no watchdog[2522]: still alive after 257667 interval(s)
Aug 30 20:03:52 no kernel: [267585.832385@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:53 no kernel: [267586.344355@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:53 no watchdog[2522]: still alive after 257668 interval(s)
Aug 30 20:03:54 no watchdog[2522]: still alive after 257669 interval(s)
Aug 30 20:03:55 no watchdog[2522]: still alive after 257670 interval(s)
Aug 30 20:03:56 no kernel: [267589.320231@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=56
Aug 30 20:03:56 no watchdog[2522]: still alive after 257671 interval(s)
Aug 30 20:03:56 no kernel: [267589.832199@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:57 no kernel: [267590.344163@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:03:57 no watchdog[2522]: still alive after 257672 interval(s)
Aug 30 20:03:58 no watchdog[2522]: still alive after 257673 interval(s)
Aug 30 20:03:59 no watchdog[2522]: still alive after 257674 interval(s)
Aug 30 20:04:00 no kernel: [267593.320028@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=00
Aug 30 20:04:00 no kernel: [267593.831992@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:00 no watchdog[2522]: still alive after 257675 interval(s)
Aug 30 20:04:01 no kernel: [267594.343971@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:01 no watchdog[2522]: still alive after 257676 interval(s)
Aug 30 20:04:02 no watchdog[2522]: still alive after 257677 interval(s)
Aug 30 20:04:03 no watchdog[2522]: still alive after 257678 interval(s)
Aug 30 20:04:04 no kernel: [267597.319837@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=04
Aug 30 20:04:04 no kernel: [267597.831809@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:04 no watchdog[2522]: still alive after 257679 interval(s)
Aug 30 20:04:05 no kernel: [267598.343776@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:05 no watchdog[2522]: still alive after 257680 interval(s)
Aug 30 20:04:06 no watchdog[2522]: still alive after 257681 interval(s)
Aug 30 20:04:07 no watchdog[2522]: still alive after 257682 interval(s)
Aug 30 20:04:08 no kernel: [267601.319627@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=08
Aug 30 20:04:08 no kernel: [267601.831603@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:08 no watchdog[2522]: still alive after 257683 interval(s)
Aug 30 20:04:09 no kernel: [267602.343574@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:09 no watchdog[2522]: still alive after 257684 interval(s)
Aug 30 20:04:10 no watchdog[2522]: still alive after 257685 interval(s)
Aug 30 20:04:11 no watchdog[2522]: still alive after 257686 interval(s)
Aug 30 20:04:12 no kernel: [267605.319431@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=12
Aug 30 20:04:12 no kernel: [267605.831408@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:12 no watchdog[2522]: still alive after 257687 interval(s)
Aug 30 20:04:13 no kernel: [267606.343375@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:13 no watchdog[2522]: still alive after 257688 interval(s)
Aug 30 20:04:14 no watchdog[2522]: still alive after 257689 interval(s)
Aug 30 20:04:15 no watchdog[2522]: still alive after 257690 interval(s)
Aug 30 20:04:16 no kernel: [267609.319266@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=16
Aug 30 20:04:16 no kernel: [267609.831236@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:16 no watchdog[2522]: still alive after 257691 interval(s)
Aug 30 20:04:17 no kernel: [267610.343208@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:17 no watchdog[2522]: still alive after 257692 interval(s)
Aug 30 20:04:18 no watchdog[2522]: still alive after 257693 interval(s)
Aug 30 20:04:19 no watchdog[2522]: still alive after 257694 interval(s)
Aug 30 20:04:20 no kernel: [267613.319055@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=20
Aug 30 20:04:20 no kernel: [267613.831007@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:20 no watchdog[2522]: still alive after 257695 interval(s)
Aug 30 20:04:21 no kernel: [267614.342991@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:21 no watchdog[2522]: still alive after 257696 interval(s)
Aug 30 20:04:22 no watchdog[2522]: still alive after 257697 interval(s)
Aug 30 20:04:23 no watchdog[2522]: still alive after 257698 interval(s)
Aug 30 20:04:24 no kernel: [267617.318847@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=24
Aug 30 20:04:24 no kernel: [267617.830817@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:24 no watchdog[2522]: still alive after 257699 interval(s)
Aug 30 20:04:25 no kernel: [267618.342787@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:25 no watchdog[2522]: still alive after 257700 interval(s)
Aug 30 20:04:26 no watchdog[2522]: still alive after 257701 interval(s)
Aug 30 20:04:27 no watchdog[2522]: still alive after 257702 interval(s)
Aug 30 20:04:28 no kernel: [267621.318669@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=28
Aug 30 20:04:28 no kernel: [267621.830624@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:28 no watchdog[2522]: still alive after 257703 interval(s)
Aug 30 20:04:29 no kernel: [267622.342597@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:29 no watchdog[2522]: still alive after 257704 interval(s)
Aug 30 20:04:30 no watchdog[2522]: still alive after 257705 interval(s)
Aug 30 20:04:31 no watchdog[2522]: still alive after 257706 interval(s)
Aug 30 20:04:32 no kernel: [267625.318460@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=32
Aug 30 20:04:32 no kernel: [267625.830406@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:32 no watchdog[2522]: still alive after 257707 interval(s)
Aug 30 20:04:33 no kernel: [267626.342395@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:33 no watchdog[2522]: still alive after 257708 interval(s)
Aug 30 20:04:34 no watchdog[2522]: still alive after 257709 interval(s)
Aug 30 20:04:35 no watchdog[2522]: still alive after 257710 interval(s)
Aug 30 20:04:36 no kernel: [267629.318268@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=36
Aug 30 20:04:36 no kernel: [267629.830227@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:36 no watchdog[2522]: still alive after 257711 interval(s)
Aug 30 20:04:37 no kernel: [267630.342204@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:37 no watchdog[2522]: still alive after 257712 interval(s)
Aug 30 20:04:38 no watchdog[2522]: still alive after 257713 interval(s)
Aug 30 20:04:40 no watchdog[2522]: still alive after 257714 interval(s)
Aug 30 20:04:40 no kernel: [267633.318060@0] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=40
Aug 30 20:04:40 no kernel: [267633.830036@0] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Aug 30 20:04:41 no watchdog[2522]: still alive after 257715 interval(s)

paulcrawford
Posts: 160
Joined: Tue May 10, 2016 11:51 am
languages_spoken: english
ODROIDs: c2 and n2
Has thanked: 19 times
Been thanked: 4 times
Contact:

Re: Problems with ntp and rtc

Unread post by paulcrawford » Sat Sep 14, 2019 3:29 am

@odroid,

So it has happened again that problems with ntp and rtc have occurred. You can see in the log below, the same kind of behaviour:

Code: Select all

Sep 12 18:43:32 no NetworkManager[2212]: <info>  [1568328212.5088] device (eth0): state change: activated -> unavailable (reason 'carrier-changed', sys-iface-state: 'managed')
Sep 12 18:43:32 no NetworkManager[2212]: <info>  [1568328212.5418] dhcp4 (eth0): canceled DHCP transaction, DHCP client pid 27568
Sep 12 18:43:32 no NetworkManager[2212]: <info>  [1568328212.5420] dhcp4 (eth0): state changed bound -> done
Sep 12 18:43:32 no NetworkManager[2212]: <info>  [1568328212.5473] manager: NetworkManager state is now CONNECTED_SITE
Sep 12 18:43:32 no NetworkManager[2212]: <info>  [1568328212.5527] manager: NetworkManager state is now CONNECTED_LOCAL
Sep 12 18:43:32 no dbus-daemon[2211]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=2212 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Sep 12 18:43:32 no NetworkManager[2212]: <info>  [1568328212.5547] manager: NetworkManager state is now DISCONNECTED
Sep 12 18:43:32 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 12 18:43:32 no dbus-daemon[2211]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 12 18:43:32 no systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 12 18:43:32 no nm-dispatcher: req:1 'connectivity-change': new request (2 scripts)
Sep 12 18:43:32 no nm-dispatcher: req:1 'connectivity-change': start running ordered scripts...
Sep 12 18:43:32 no nm-dispatcher: req:2 'down' [eth0]: new request (2 scripts)
Sep 12 18:43:32 no nm-dispatcher: req:2 'down' [eth0]: start running ordered scripts...
Sep 12 18:43:32 no datacoll[3291]: in0: fffff6c6 in1: 9 in2: 33 in3: fffffffe in4: 61fb in5: fffffffe in6: only 1 bytes read on wnc
Sep 12 18:43:32 no watchdog[2624]: still alive after 325018 interval(s)
Sep 12 18:43:32 no datacoll[3291]: only 7 bytes read on wj28
Sep 12 18:43:32 no datacoll[3291]: failed on wnc channel 4 retry using mult 4 error: 0
Sep 12 18:43:32 no datacoll[3291]: fffffffe in7: fffffffe
Sep 12 18:43:32 no datacoll[3291]: goodcrc wj28-r[0]: 1, [1]: 3, [2]: 10, [3]: f6, [4]: c6, [5]: 0, [6]: 9, [7]: 0, [8]: 33, [9]: ff
Sep 12 18:43:32 no datacoll[3291]: [10]: fe, [11]: 61, [12]: fb, [13]: ff, [14]: fe, [15]: ff, [16]: fe, [17]: ff, [18]: fe, [19]: d4, [20]: 93
Sep 12 18:43:32 no datacoll[3291]: duty0 changed
Sep 12 18:43:32 no datacoll[3291]: top of dbselect captestflags: 101
Sep 12 18:43:32 no datacoll[3291]: charging: 0 CSW: 0 firsttime 0
Sep 12 18:43:32 no datacoll[3291]: runcaptest from db: 1 captestrunning from flags: 1
Sep 12 18:43:32 no datacoll[3291]: ctr: 1 ptr: 0
Sep 12 18:43:32 no datacoll[3291]: it: 0 id: 0
Sep 12 18:43:32 no datacoll[3291]: inside set pwm captestflags: 101
Sep 12 18:43:33 no datacoll[3291]: btdata.c20cap: -21.6500 b1a.present: -1.0813
Sep 12 18:43:33 no datacoll[3291]: deltac: -0.0012
Sep 12 18:43:33 no datacoll[3291]: deltacr: -1.1360 lcstate: 5162496
Sep 12 18:43:33 no datacoll[3291]: deltacurrent: -1.136 pwm: 5162496 deltacurrent x pwm: -587
Sep 12 18:43:33 no datacoll[3291]: currentreq: -1.08 currentact: -1.08 delta: -587 firsttimeload: 0
Sep 12 18:43:33 no datacoll[3291]: lc.present 5163083.0000
Sep 12 18:43:33 no datacoll[3291]: setting dischargetime
Sep 12 18:43:33 no datacoll[3291]: b1v: 12.25 terminalvoltage: 10.50
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: sp: 4 highcur: 1
Sep 12 18:43:33 no datacoll[3291]: sp: 4 sg msg: 8,5c,0,2,c0,c2,40,0,80,43 ./bmetest 102 127 0 253 74 0 21 154 cb,16, 9a,8
Sep 12 18:43:33 no datacoll[3291]: #033[34m27 bytes read on smartgauge#033[0m
Sep 12 18:43:33 no datacoll[3291]: 8,5c,0,2,c0,c2,40,0,80,43,66,7f,0,fd,4a,0,15,9a,cb,16,9a,8,3a,a7,0,c8,5,0,0
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: about to write msg to port: 4
Sep 12 18:43:33 no datacoll[3291]: res: 8
Sep 12 18:43:33 no datacoll[3291]: about to read rsp from port: 4 WNRESPONSESIZE: 37
Sep 12 18:43:33 no datacoll[3291]: #033[31m37 bytes read on wnc#033[0m
Sep 12 18:43:33 no datacoll[3291]: wnc1-r[0]: 1, [1]: 3, [2]: 20, [3]: d3, [4]: 4e, [5]: 44, [6]: 5d, [7]: 54, [8]: e5, [9]: 43, [10]: 92, [11]: 0, [12]: 0, [35]: 78, [36]: bf
Sep 12 18:43:33 no datacoll[3291]: wnc read
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: about to read rsp from port: 4 WJ28RESPONSESIZE: 21
Sep 12 18:43:33 no datacoll[3291]: #033[32m21 bytes read on wj28#033[0m
Sep 12 18:43:33 no datacoll[3291]: in0: fffff6c2 in1: 9 in2: 33 in3: fffffffe in4: 61fb in5: fffffffe in6: fffffffe in7: fffffffe
Sep 12 18:43:33 no datacoll[3291]: goodcrc wj28-r[0]: 1, [1]: 3, [2]: 10, [3]: f6, [4]: c2, [5]: 0, [6]: 9, [7]: 0, [8]: 33, [9]: ff
Sep 12 18:43:33 no datacoll[3291]: [10]: fe, [11]: 61, [12]: fb, [13]: ff, [14]: fe, [15]: ff, [16]: fe, [17]: ff, [18]: fe, [19]: d0, [20]: 90
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: top of dbselect captestflags: 101
Sep 12 18:43:33 no datacoll[3291]: charging: 0 CSW: 0 firsttime 0
Sep 12 18:43:33 no datacoll[3291]: runcaptest from db: 1 captestrunning from flags: 1
Sep 12 18:43:33 no datacoll[3291]: ctr: 1 ptr: 0
Sep 12 18:43:33 no datacoll[3291]: it: 0 id: 0
Sep 12 18:43:33 no datacoll[3291]: inside set pwm captestflags: 101
Sep 12 18:43:33 no datacoll[3291]: btdata.c20cap: -21.6500 b1a.present: -1.0831
Sep 12 18:43:33 no datacoll[3291]: deltac: 0.0006
Sep 12 18:43:33 no datacoll[3291]: deltacr: 0.5556 lcstate: 5163083
Sep 12 18:43:33 no datacoll[3291]: deltacurrent:  0.556 pwm: 5163083 deltacurrent x pwm: 287
Sep 12 18:43:33 no datacoll[3291]: currentreq: -1.08 currentact: -1.08 delta: 287 firsttimeload: 0
Sep 12 18:43:33 no datacoll[3291]: lc.present 5162796.0000
Sep 12 18:43:33 no datacoll[3291]: setting dischargetime
Sep 12 18:43:33 no datacoll[3291]: b1v: 12.25 terminalvoltage: 10.50
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: sp: 4 highcur: 1
Sep 12 18:43:33 no datacoll[3291]: sp: 4 sg msg: 8,60,0,3,40,c2,80,0,40,43 ./bmetest 102 127 0 253 74 0 21 154 cb,16, 9a,8
Sep 12 18:43:33 no datacoll[3291]: #033[34m27 bytes read on smartgauge#033[0m
Sep 12 18:43:33 no datacoll[3291]: 8,60,0,3,40,c2,80,0,40,43,66,7f,0,fd,4a,0,15,9a,cb,16,9a,8,49,a7,0,9b,9e,0,0
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: about to write msg to port: 4
Sep 12 18:43:33 no datacoll[3291]: res: 8
Sep 12 18:43:33 no datacoll[3291]: about to read rsp from port: 4 WNRESPONSESIZE: 37
Sep 12 18:43:33 no datacoll[3291]: #033[31m37 bytes read on wnc#033[0m
Sep 12 18:43:33 no datacoll[3291]: wnc1-r[0]: 1, [1]: 3, [2]: 20, [3]: d3, [4]: 50, [5]: 44, [6]: 5d, [7]: 54, [8]: e5, [9]: 43, [10]: 92, [11]: 0, [12]: 0, [35]: ac, [36]: 54
Sep 12 18:43:33 no datacoll[3291]: wnc read
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: about to read rsp from port: 4 WJ28RESPONSESIZE: 21
Sep 12 18:43:33 no datacoll[3291]: #033[32m21 bytes read on wj28#033[0m
Sep 12 18:43:33 no datacoll[3291]: in0: fffff6c7 in1: 9 in2: 32 in3: fffffffe in4: 61fb in5: fffffffe in6: fffffffe in7: fffffffe
Sep 12 18:43:33 no datacoll[3291]: goodcrc wj28-r[0]: 1, [1]: 3, [2]: 10, [3]: f6, [4]: c7, [5]: 0, [6]: 9, [7]: 0, [8]: 32, [9]: ff
Sep 12 18:43:33 no datacoll[3291]: [10]: fe, [11]: 61, [12]: fb, [13]: ff, [14]: fe, [15]: ff, [16]: fe, [17]: ff, [18]: fe, [19]: 11, [20]: 6f
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: top of dbselect captestflags: 101
Sep 12 18:43:33 no datacoll[3291]: charging: 0 CSW: 0 firsttime 0
Sep 12 18:43:33 no datacoll[3291]: runcaptest from db: 1 captestrunning from flags: 1
Sep 12 18:43:33 no datacoll[3291]: ctr: 1 ptr: 0
Sep 12 18:43:33 no datacoll[3291]: it: 0 id: 0
Sep 12 18:43:33 no datacoll[3291]: inside set pwm captestflags: 101
Sep 12 18:43:33 no datacoll[3291]: btdata.c20cap: -21.6500 b1a.present: -1.0808
Sep 12 18:43:33 no datacoll[3291]: deltac: -0.0017
Sep 12 18:43:33 no datacoll[3291]: deltacr: -1.5589 lcstate: 5162796
Sep 12 18:43:33 no datacoll[3291]: deltacurrent: -1.559 pwm: 5162796 deltacurrent x pwm: -805
Sep 12 18:43:33 no datacoll[3291]: currentreq: -1.08 currentact: -1.08 delta: -805 firsttimeload: 0
Sep 12 18:43:33 no datacoll[3291]: lc.present 5163601.0000
Sep 12 18:43:33 no datacoll[3291]: setting dischargetime
Sep 12 18:43:33 no datacoll[3291]: b1v: 12.25 terminalvoltage: 10.50
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: sp: 4 highcur: 1
Sep 12 18:43:33 no datacoll[3291]: sp: 4 sg msg: 8,60,0,3,0,c1,c0,0,80,43 ./bmetest 102 127 0 253 74 0 21 154 cb,16, 9a,8
Sep 12 18:43:33 no datacoll[3291]: #033[34m27 bytes read on smartgauge#033[0m
Sep 12 18:43:33 no datacoll[3291]: 8,60,0,3,0,c1,c0,0,80,43,66,7f,0,fd,4a,0,15,9a,cb,16,9a,8,4e,a7,0,98,5d,0,0
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: about to write msg to port: 4
Sep 12 18:43:33 no datacoll[3291]: res: 8
Sep 12 18:43:33 no datacoll[3291]: about to read rsp from port: 4 WNRESPONSESIZE: 37
Sep 12 18:43:33 no datacoll[3291]: wnc1-r[0]: 0, [1]: ff, [2]: ff
Sep 12 18:43:33 no datacoll[3291]: wnc read
Sep 12 18:43:33 no datacoll[3291]: duty0 changed
Sep 12 18:43:33 no datacoll[3291]: about to read rsp from port: 4 WJ28RESPONSESIZE: 21
Sep 12 18:43:33 no kernel: [334485.959626@0] meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 38400 to 9600
Sep 12 18:43:33 no kernel: [334486.110893@0] meson_uart ffd24000.serial: ttyS1 use xtal(24M) 24000000 change 9600 to 38400
Sep 12 18:43:33 no watchdog[2624]: still alive after 325019 interval(s)
Sep 12 18:43:34 no watchdog[2624]: still alive after 325020 interval(s)
Sep 12 18:43:35 no watchdog[2624]: still alive after 325021 interval(s)
Sep 12 18:43:36 no watchdog[2624]: still alive after 325022 interval(s)
Sep 12 18:43:37 no watchdog[2624]: still alive after 325023 interval(s)
Sep 12 18:43:38 no watchdog[2624]: still alive after 325024 interval(s)
Sep 12 18:43:39 no watchdog[2624]: still alive after 325025 interval(s)
Sep 12 18:43:40 no watchdog[2624]: still alive after 325026 interval(s)
Sep 12 18:43:41 no watchdog[2624]: still alive after 325027 interval(s)
Sep 12 18:43:42 no watchdog[2624]: still alive after 325028 interval(s)
Sep 12 18:43:43 no watchdog[2624]: still alive after 325029 interval(s)
Sep 12 18:43:44 no watchdog[2624]: still alive after 325030 interval(s)
Sep 12 18:43:45 no watchdog[2624]: still alive after 325031 interval(s)
Sep 12 18:43:46 no watchdog[2624]: still alive after 325032 interval(s)
Sep 12 18:43:47 no watchdog[2624]: still alive after 325033 interval(s)
Sep 12 18:43:49 no watchdog[2624]: still alive after 325034 interval(s)
Sep 12 18:43:50 no watchdog[2624]: still alive after 325035 interval(s)
Sep 12 18:43:51 no watchdog[2624]: still alive after 325036 interval(s)
Sep 12 18:43:52 no watchdog[2624]: still alive after 325037 interval(s)
Sep 12 18:43:53 no watchdog[2624]: still alive after 325038 interval(s)
Sep 12 18:43:54 no watchdog[2624]: still alive after 325039 interval(s)
Sep 12 18:43:55 no watchdog[2624]: still alive after 325040 interval(s)
Sep 12 18:43:56 no watchdog[2624]: still alive after 325041 interval(s)
Sep 12 18:43:57 no watchdog[2624]: still alive after 325042 interval(s)
Sep 12 18:43:58 no watchdog[2624]: still alive after 325043 interval(s)
Sep 12 18:43:59 no watchdog[2624]: still alive after 325044 interval(s)
Sep 12 18:44:00 no watchdog[2624]: still alive after 325045 interval(s)
Sep 12 18:44:01 no watchdog[2624]: still alive after 325046 interval(s)
Sep 12 18:44:02 no watchdog[2624]: still alive after 325047 interval(s)
Sep 12 18:44:03 no watchdog[2624]: still alive after 325048 interval(s)
Sep 12 18:44:04 no watchdog[2624]: still alive after 325049 interval(s)
Sep 12 18:44:05 no watchdog[2624]: still alive after 325050 interval(s)
Sep 12 18:44:06 no kernel: [334518.280699@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=06
Sep 12 18:44:06 no watchdog[2624]: still alive after 325051 interval(s)
Sep 12 18:44:06 no kernel: [334518.792685@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:07 no kernel: [334519.304635@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:07 no watchdog[2624]: still alive after 325052 interval(s)
Sep 12 18:44:08 no watchdog[2624]: still alive after 325053 interval(s)
Sep 12 18:44:09 no kernel: [334521.288535@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=09
Sep 12 18:44:09 no watchdog[2624]: still alive after 325054 interval(s)
Sep 12 18:44:09 no kernel: [334521.800543@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:10 no kernel: [334522.312484@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:10 no watchdog[2624]: still alive after 325055 interval(s)
Sep 12 18:44:11 no watchdog[2624]: still alive after 325056 interval(s)
Sep 12 18:44:12 no watchdog[2624]: still alive after 325057 interval(s)
Sep 12 18:44:13 no kernel: [334525.288332@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=13
Sep 12 18:44:13 no watchdog[2624]: still alive after 325058 interval(s)
Sep 12 18:44:13 no kernel: [334525.800325@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:13 no kernel: [334525.864584@1] meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6036] device (eth0): carrier: link connected
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6057] device (eth0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6098] policy: auto-activating connection 'Wired connection 1'
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6232] device (eth0): Activation: starting connection 'Wired connection 1' (d19dbcdd-02e7-3a28-ad6c-c292c1033b0a)
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6270] device (eth0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6297] manager: NetworkManager state is now CONNECTING
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6356] device (eth0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6400] device (eth0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6437] dhcp4 (eth0): activation: beginning transaction (timeout in 45 seconds)
Sep 12 18:44:13 no NetworkManager[2212]: <info>  [1568328253.6507] dhcp4 (eth0): dhclient started with pid 19605
Sep 12 18:44:13 no dhclient[19605]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x1bccee8d)
Sep 12 18:44:14 no kernel: [334526.312272@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:14 no watchdog[2624]: still alive after 325059 interval(s)
Sep 12 18:44:14 no ntpd[2257]: bind(23) AF_INET6 fe80::5a98:2039:1692:5af3%2#123 flags 0x11 failed: Cannot assign requested address
Sep 12 18:44:14 no ntpd[2257]: unable to create socket on eth0 (8) for fe80::5a98:2039:1692:5af3%2#123
Sep 12 18:44:14 no ntpd[2257]: failed to init interface for address fe80::5a98:2039:1692:5af3%2
Sep 12 18:44:15 no watchdog[2624]: still alive after 325060 interval(s)
Sep 12 18:44:16 no dhclient[19605]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x1bccee8d)
Sep 12 18:44:16 no watchdog[2624]: still alive after 325061 interval(s)
Sep 12 18:44:16 no ntpd[2257]: Listen normally on 9 eth0 [fe80::5a98:2039:1692:5af3%2]:123
Sep 12 18:44:16 no ntpd[2257]: new interface(s) found: waking up resolver
Sep 12 18:44:17 no kernel: [334529.288158@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=17
Sep 12 18:44:17 no watchdog[2624]: still alive after 325062 interval(s)
Sep 12 18:44:17 no kernel: [334529.800121@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:18 no kernel: [334530.312066@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:18 no watchdog[2624]: still alive after 325063 interval(s)
Sep 12 18:44:19 no watchdog[2624]: still alive after 325064 interval(s)
Sep 12 18:44:20 no watchdog[2624]: still alive after 325065 interval(s)
Sep 12 18:44:20 no dhclient[19605]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x1bccee8d)
Sep 12 18:44:21 no kernel: [334533.287953@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=21
Sep 12 18:44:21 no watchdog[2624]: still alive after 325066 interval(s)
Sep 12 18:44:21 no kernel: [334533.799912@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:22 no kernel: [334534.311864@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:22 no watchdog[2624]: still alive after 325067 interval(s)
Sep 12 18:44:23 no watchdog[2624]: still alive after 325068 interval(s)
Sep 12 18:44:24 no watchdog[2624]: still alive after 325069 interval(s)
Sep 12 18:44:25 no kernel: [334537.287751@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=25
Sep 12 18:44:25 no watchdog[2624]: still alive after 325070 interval(s)
Sep 12 18:44:25 no kernel: [334537.799713@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:26 no kernel: [334538.311667@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:26 no watchdog[2624]: still alive after 325071 interval(s)
Sep 12 18:44:27 no watchdog[2624]: still alive after 325072 interval(s)
Sep 12 18:44:28 no watchdog[2624]: still alive after 325073 interval(s)
Sep 12 18:44:29 no kernel: [334541.287545@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=29
Sep 12 18:44:29 no watchdog[2624]: still alive after 325074 interval(s)
Sep 12 18:44:29 no kernel: [334541.799506@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:30 no kernel: [334542.311463@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:30 no watchdog[2624]: still alive after 325075 interval(s)
Sep 12 18:44:30 no dhclient[19605]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0x1a4b2922)
Sep 12 18:44:30 no dhclient[19605]: DHCPREQUEST of 192.168.10.240 on eth0 to 255.255.255.255 port 67 (xid=0x22294b1a)
Sep 12 18:44:30 no dhclient[19605]: DHCPOFFER of 192.168.10.240 from 192.168.10.1
Sep 12 18:44:30 no dhclient[19605]: DHCPACK of 192.168.10.240 from 192.168.10.1
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8119] dhcp4 (eth0):   address 192.168.10.240
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8121] dhcp4 (eth0):   plen 24 (255.255.255.0)
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8122] dhcp4 (eth0):   gateway 192.168.10.1
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8123] dhcp4 (eth0):   lease time 1200
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8125] dhcp4 (eth0):   nameserver '192.168.10.1'
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8125] dhcp4 (eth0):   domain name 'cgocable.net'
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8127] dhcp4 (eth0): state changed unknown -> bound
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8266] device (eth0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8347] device (eth0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8363] device (eth0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8372] manager: NetworkManager state is now CONNECTED_LOCAL
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8431] manager: NetworkManager state is now CONNECTED_SITE
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8443] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Sep 12 18:44:30 no dhclient[19605]: bound to 192.168.10.240 -- renewal in 456 seconds.
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8511] device (eth0): Activation: successful, device activated.
Sep 12 18:44:30 no dbus-daemon[2211]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=2212 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Sep 12 18:44:30 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 12 18:44:30 no NetworkManager[2212]: <info>  [1568328270.8630] manager: NetworkManager state is now CONNECTED_GLOBAL
Sep 12 18:44:30 no dbus-daemon[2211]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 12 18:44:30 no systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 12 18:44:30 no nm-dispatcher: req:1 'up' [eth0]: new request (2 scripts)
Sep 12 18:44:30 no nm-dispatcher: req:1 'up' [eth0]: start running ordered scripts...
Sep 12 18:44:30 no nm-dispatcher: req:2 'connectivity-change': new request (2 scripts)
Sep 12 18:44:30 no systemd[1]: Reloading OpenBSD Secure Shell server.
Sep 12 18:44:30 no systemd-resolved[2206]: Using degraded feature set (UDP) for DNS server 192.168.10.1.
Sep 12 18:44:31 no systemd[1]: Reloaded OpenBSD Secure Shell server.
Sep 12 18:44:31 no systemd[1]: Reloading OpenBSD Secure Shell server.
Sep 12 18:44:31 no systemd[1]: Reloaded OpenBSD Secure Shell server.
Sep 12 18:44:31 no nm-dispatcher: req:2 'connectivity-change': start running ordered scripts...
Sep 12 18:44:31 no watchdog[2624]: still alive after 325076 interval(s)
Sep 12 18:44:31 no ntpd[2257]: Listen normally on 10 eth0 192.168.10.240:123
Sep 12 18:44:31 no ntpd[2257]: new interface(s) found: waking up resolver
Sep 12 18:44:32 no watchdog[2624]: still alive after 325077 interval(s)
Sep 12 18:44:32 no ntpd[2257]: Soliciting pool server 2001:67c:1560:8003::c8
Sep 12 18:44:33 no kernel: [334545.287348@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=33
Sep 12 18:44:33 no watchdog[2624]: still alive after 325078 interval(s)
Sep 12 18:44:33 no kernel: [334545.799296@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:34 no kernel: [334546.311261@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:34 no watchdog[2624]: still alive after 325079 interval(s)
Sep 12 18:44:35 no watchdog[2624]: still alive after 325080 interval(s)
Sep 12 18:44:36 no ntpdate[19637]: the NTP socket is in use, exiting
Sep 12 18:44:36 no watchdog[2624]: still alive after 325081 interval(s)
Sep 12 18:44:37 no kernel: [334549.287153@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=37
Sep 12 18:44:37 no kernel: [334549.799118@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:37 no watchdog[2624]: still alive after 325082 interval(s)
Sep 12 18:44:38 no kernel: [334550.311058@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:38 no watchdog[2624]: still alive after 325083 interval(s)
Sep 12 18:44:39 no watchdog[2624]: still alive after 325084 interval(s)
Sep 12 18:44:40 no watchdog[2624]: still alive after 325085 interval(s)
Sep 12 18:44:41 no kernel: [334553.286940@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=41
Sep 12 18:44:41 no kernel: [334553.798910@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:41 no watchdog[2624]: still alive after 325086 interval(s)
Sep 12 18:44:42 no kernel: [334554.310862@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:42 no watchdog[2624]: still alive after 325087 interval(s)
Sep 12 18:44:43 no watchdog[2624]: still alive after 325088 interval(s)
Sep 12 18:44:44 no watchdog[2624]: still alive after 325089 interval(s)
Sep 12 18:44:45 no kernel: [334557.286731@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=45
Sep 12 18:44:45 no kernel: [334557.798716@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:45 no watchdog[2624]: still alive after 325090 interval(s)
Sep 12 18:44:46 no kernel: [334558.310655@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:46 no watchdog[2624]: still alive after 325091 interval(s)
Sep 12 18:44:47 no watchdog[2624]: still alive after 325092 interval(s)
Sep 12 18:44:48 no watchdog[2624]: still alive after 325093 interval(s)
Sep 12 18:44:49 no kernel: [334561.286526@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=49
Sep 12 18:44:49 no kernel: [334561.798509@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:49 no watchdog[2624]: still alive after 325094 interval(s)
Sep 12 18:44:50 no kernel: [334562.310456@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:50 no watchdog[2624]: still alive after 325095 interval(s)
Sep 12 18:44:51 no watchdog[2624]: still alive after 325096 interval(s)
Sep 12 18:44:52 no watchdog[2624]: still alive after 325097 interval(s)
Sep 12 18:44:53 no kernel: [334565.286318@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=53
Sep 12 18:44:53 no kernel: [334565.798309@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:53 no watchdog[2624]: still alive after 325098 interval(s)
Sep 12 18:44:54 no kernel: [334566.310250@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:54 no watchdog[2624]: still alive after 325099 interval(s)
Sep 12 18:44:55 no watchdog[2624]: still alive after 325100 interval(s)
Sep 12 18:44:56 no watchdog[2624]: still alive after 325101 interval(s)
Sep 12 18:44:57 no kernel: [334569.286136@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=57
Sep 12 18:44:57 no kernel: [334569.798111@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:57 no watchdog[2624]: still alive after 325102 interval(s)
Sep 12 18:44:58 no kernel: [334570.310053@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:44:58 no watchdog[2624]: still alive after 325103 interval(s)
Sep 12 18:44:59 no watchdog[2624]: still alive after 325104 interval(s)
Sep 12 18:45:00 no watchdog[2624]: still alive after 325105 interval(s)
Sep 12 18:45:01 no kernel: [334573.285933@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=01
Sep 12 18:45:01 no kernel: [334573.797899@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:01 no watchdog[2624]: still alive after 325106 interval(s)
Sep 12 18:45:02 no kernel: [334574.309847@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:02 no watchdog[2624]: still alive after 325107 interval(s)
Sep 12 18:45:03 no watchdog[2624]: still alive after 325108 interval(s)
Sep 12 18:45:04 no watchdog[2624]: still alive after 325109 interval(s)
Sep 12 18:45:05 no kernel: [334577.285733@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=05
Sep 12 18:45:05 no kernel: [334577.797691@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:05 no watchdog[2624]: still alive after 325110 interval(s)
Sep 12 18:45:06 no kernel: [334578.309648@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:06 no watchdog[2624]: still alive after 325111 interval(s)
Sep 12 18:45:07 no watchdog[2624]: still alive after 325112 interval(s)
Sep 12 18:45:08 no watchdog[2624]: still alive after 325113 interval(s)
Sep 12 18:45:09 no kernel: [334581.285533@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=09
Sep 12 18:45:09 no kernel: [334581.797487@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:09 no watchdog[2624]: still alive after 325114 interval(s)
Sep 12 18:45:10 no kernel: [334582.309445@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:10 no watchdog[2624]: still alive after 325115 interval(s)
Sep 12 18:45:11 no watchdog[2624]: still alive after 325116 interval(s)
Sep 12 18:45:12 no watchdog[2624]: still alive after 325117 interval(s)
Sep 12 18:45:13 no kernel: [334585.285357@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=13
Sep 12 18:45:13 no kernel: [334585.797276@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:13 no watchdog[2624]: still alive after 325118 interval(s)
Sep 12 18:45:14 no kernel: [334586.309245@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:15 no watchdog[2624]: still alive after 325119 interval(s)
Sep 12 18:45:16 no watchdog[2624]: still alive after 325120 interval(s)
Sep 12 18:45:17 no watchdog[2624]: still alive after 325121 interval(s)
Sep 12 18:45:17 no kernel: [334589.285128@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=17
Sep 12 18:45:17 no kernel: [334589.797072@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:18 no watchdog[2624]: still alive after 325122 interval(s)
Sep 12 18:45:18 no kernel: [334590.309044@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:19 no watchdog[2624]: still alive after 325123 interval(s)
Sep 12 18:45:20 no watchdog[2624]: still alive after 325124 interval(s)
Sep 12 18:45:21 no kernel: [334593.284920@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=21
Sep 12 18:45:21 no watchdog[2624]: still alive after 325125 interval(s)
Sep 12 18:45:21 no kernel: [334593.796899@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:22 no kernel: [334594.308836@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:22 no watchdog[2624]: still alive after 325126 interval(s)
Sep 12 18:45:23 no watchdog[2624]: still alive after 325127 interval(s)
Sep 12 18:45:24 no watchdog[2624]: still alive after 325128 interval(s)
Sep 12 18:45:25 no kernel: [334597.284714@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=25
Sep 12 18:45:25 no watchdog[2624]: still alive after 325129 interval(s)
Sep 12 18:45:25 no kernel: [334597.796693@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:26 no kernel: [334598.308634@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:26 no watchdog[2624]: still alive after 325130 interval(s)
Sep 12 18:45:27 no watchdog[2624]: still alive after 325131 interval(s)
Sep 12 18:45:28 no watchdog[2624]: still alive after 325132 interval(s)
Sep 12 18:45:29 no kernel: [334601.284505@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=29
Sep 12 18:45:29 no watchdog[2624]: still alive after 325133 interval(s)
Sep 12 18:45:29 no kernel: [334601.796492@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:30 no kernel: [334602.308435@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:30 no watchdog[2624]: still alive after 325134 interval(s)
Sep 12 18:45:31 no watchdog[2624]: still alive after 325135 interval(s)
Sep 12 18:45:32 no watchdog[2624]: still alive after 325136 interval(s)
Sep 12 18:45:33 no kernel: [334605.284301@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=33
Sep 12 18:45:33 no watchdog[2624]: still alive after 325137 interval(s)
Sep 12 18:45:33 no kernel: [334605.796291@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:34 no kernel: [334606.308231@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:34 no watchdog[2624]: still alive after 325138 interval(s)
Sep 12 18:45:35 no watchdog[2624]: still alive after 325139 interval(s)
Sep 12 18:45:36 no watchdog[2624]: still alive after 325140 interval(s)
Sep 12 18:45:37 no kernel: [334609.284095@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=37
Sep 12 18:45:37 no watchdog[2624]: still alive after 325141 interval(s)
Sep 12 18:45:37 no kernel: [334609.796088@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:38 no kernel: [334610.308032@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:38 no watchdog[2624]: still alive after 325142 interval(s)
Sep 12 18:45:39 no watchdog[2624]: still alive after 325143 interval(s)
Sep 12 18:45:40 no watchdog[2624]: still alive after 325144 interval(s)
Sep 12 18:45:41 no kernel: [334613.283916@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=41
Sep 12 18:45:41 no watchdog[2624]: still alive after 325145 interval(s)
Sep 12 18:45:41 no kernel: [334613.795885@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:42 no kernel: [334614.307828@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:42 no watchdog[2624]: still alive after 325146 interval(s)
Sep 12 18:45:43 no watchdog[2624]: still alive after 325147 interval(s)
Sep 12 18:45:44 no watchdog[2624]: still alive after 325148 interval(s)
Sep 12 18:45:45 no kernel: [334617.283710@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=45
Sep 12 18:45:45 no watchdog[2624]: still alive after 325149 interval(s)
Sep 12 18:45:45 no kernel: [334617.795680@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:46 no kernel: [334618.307625@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:46 no watchdog[2624]: still alive after 325150 interval(s)
Sep 12 18:45:47 no watchdog[2624]: still alive after 325151 interval(s)
Sep 12 18:45:48 no watchdog[2624]: still alive after 325152 interval(s)
Sep 12 18:45:49 no kernel: [334621.283510@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=49
Sep 12 18:45:49 no watchdog[2624]: still alive after 325153 interval(s)
Sep 12 18:45:49 no kernel: [334621.795472@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:50 no kernel: [334622.307429@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:51 no watchdog[2624]: still alive after 325154 interval(s)
Sep 12 18:45:52 no watchdog[2624]: still alive after 325155 interval(s)
Sep 12 18:45:53 no kernel: [334625.283313@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=53
Sep 12 18:45:53 no kernel: [334625.795262@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:53 no watchdog[2624]: still alive after 325156 interval(s)
Sep 12 18:45:54 no kernel: [334626.307222@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:54 no watchdog[2624]: still alive after 325157 interval(s)
Sep 12 18:45:55 no watchdog[2624]: still alive after 325158 interval(s)
Sep 12 18:45:56 no watchdog[2624]: still alive after 325159 interval(s)
Sep 12 18:45:57 no kernel: [334629.283108@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=57
Sep 12 18:45:57 no kernel: [334629.795058@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:57 no watchdog[2624]: still alive after 325160 interval(s)
Sep 12 18:45:58 no kernel: [334630.307024@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:45:58 no watchdog[2624]: still alive after 325161 interval(s)
Sep 12 18:45:59 no watchdog[2624]: still alive after 325162 interval(s)
Sep 12 18:46:00 no watchdog[2624]: still alive after 325163 interval(s)
Sep 12 18:46:01 no kernel: [334633.282910@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=01
Sep 12 18:46:01 no kernel: [334633.794879@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:01 no watchdog[2624]: still alive after 325164 interval(s)
Sep 12 18:46:02 no kernel: [334634.306827@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:03 no watchdog[2624]: still alive after 325165 interval(s)
Sep 12 18:46:04 no watchdog[2624]: still alive after 325166 interval(s)
Sep 12 18:46:05 no kernel: [334637.282701@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=05
Sep 12 18:46:05 no watchdog[2624]: still alive after 325167 interval(s)
Sep 12 18:46:05 no kernel: [334637.794672@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:06 no watchdog[2624]: still alive after 325168 interval(s)
Sep 12 18:46:06 no kernel: [334638.306626@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:07 no watchdog[2624]: still alive after 325169 interval(s)
Sep 12 18:46:08 no watchdog[2624]: still alive after 325170 interval(s)
Sep 12 18:46:09 no kernel: [334641.282493@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=09
Sep 12 18:46:09 no watchdog[2624]: still alive after 325171 interval(s)
Sep 12 18:46:09 no kernel: [334641.794476@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:10 no kernel: [334642.306416@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:10 no watchdog[2624]: still alive after 325172 interval(s)
Sep 12 18:46:11 no watchdog[2624]: still alive after 325173 interval(s)
Sep 12 18:46:12 no watchdog[2624]: still alive after 325174 interval(s)
Sep 12 18:46:13 no kernel: [334645.282282@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=13
Sep 12 18:46:13 no watchdog[2624]: still alive after 325175 interval(s)
Sep 12 18:46:13 no kernel: [334645.794270@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:14 no kernel: [334646.306212@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:14 no watchdog[2624]: still alive after 325176 interval(s)
Sep 12 18:46:15 no watchdog[2624]: still alive after 325177 interval(s)
Sep 12 18:46:16 no watchdog[2624]: still alive after 325178 interval(s)
Sep 12 18:46:17 no kernel: [334649.282079@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=17
Sep 12 18:46:17 no watchdog[2624]: still alive after 325179 interval(s)
Sep 12 18:46:17 no kernel: [334649.794085@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:18 no kernel: [334650.306031@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:18 no watchdog[2624]: still alive after 325180 interval(s)
Sep 12 18:46:19 no watchdog[2624]: still alive after 325181 interval(s)
Sep 12 18:46:20 no watchdog[2624]: still alive after 325182 interval(s)
Sep 12 18:46:21 no kernel: [334653.281871@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=21
Sep 12 18:46:21 no watchdog[2624]: still alive after 325183 interval(s)
Sep 12 18:46:21 no kernel: [334653.793871@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:22 no kernel: [334654.305810@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:22 no watchdog[2624]: still alive after 325184 interval(s)
Sep 12 18:46:23 no watchdog[2624]: still alive after 325185 interval(s)
Sep 12 18:46:24 no watchdog[2624]: still alive after 325186 interval(s)
Sep 12 18:46:25 no kernel: [334657.281696@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=25
Sep 12 18:46:25 no watchdog[2624]: still alive after 325187 interval(s)
Sep 12 18:46:25 no kernel: [334657.793662@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:26 no kernel: [334658.305611@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:26 no watchdog[2624]: still alive after 325188 interval(s)
Sep 12 18:46:27 no watchdog[2624]: still alive after 325189 interval(s)
Sep 12 18:46:28 no watchdog[2624]: still alive after 325190 interval(s)
Sep 12 18:46:29 no kernel: [334661.281492@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=29
Sep 12 18:46:29 no watchdog[2624]: still alive after 325191 interval(s)
Sep 12 18:46:29 no kernel: [334661.793456@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:30 no kernel: [334662.305408@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:30 no watchdog[2624]: still alive after 325192 interval(s)
Sep 12 18:46:31 no watchdog[2624]: still alive after 325193 interval(s)
Sep 12 18:46:32 no watchdog[2624]: still alive after 325194 interval(s)
Sep 12 18:46:33 no kernel: [334665.281289@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=33
Sep 12 18:46:33 no watchdog[2624]: still alive after 325195 interval(s)
Sep 12 18:46:33 no kernel: [334665.793253@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:34 no kernel: [334666.305203@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:34 no watchdog[2624]: still alive after 325196 interval(s)
Sep 12 18:46:35 no watchdog[2624]: still alive after 325197 interval(s)
Sep 12 18:46:36 no watchdog[2624]: still alive after 325198 interval(s)
Sep 12 18:46:37 no kernel: [334669.281085@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=37
Sep 12 18:46:37 no watchdog[2624]: still alive after 325199 interval(s)
Sep 12 18:46:37 no kernel: [334669.793040@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:38 no kernel: [334670.305001@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:38 no watchdog[2624]: still alive after 325200 interval(s)
Sep 12 18:46:39 no watchdog[2624]: still alive after 325201 interval(s)
Sep 12 18:46:40 no watchdog[2624]: still alive after 325202 interval(s)
Sep 12 18:46:41 no kernel: [334673.280886@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=41
Sep 12 18:46:41 no watchdog[2624]: still alive after 325203 interval(s)
Sep 12 18:46:41 no kernel: [334673.792836@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:42 no kernel: [334674.304801@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:42 no watchdog[2624]: still alive after 325204 interval(s)
Sep 12 18:46:43 no watchdog[2624]: still alive after 325205 interval(s)
Sep 12 18:46:44 no watchdog[2624]: still alive after 325206 interval(s)
Sep 12 18:46:45 no kernel: [334677.280684@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=45
Sep 12 18:46:45 no watchdog[2624]: still alive after 325207 interval(s)
Sep 12 18:46:45 no kernel: [334677.792663@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:46 no kernel: [334678.304605@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:46 no watchdog[2624]: still alive after 325208 interval(s)
Sep 12 18:46:47 no watchdog[2624]: still alive after 325209 interval(s)
Sep 12 18:46:48 no watchdog[2624]: still alive after 325210 interval(s)
Sep 12 18:46:49 no kernel: [334681.280485@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=49
Sep 12 18:46:49 no watchdog[2624]: still alive after 325211 interval(s)
Sep 12 18:46:49 no kernel: [334681.792455@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:50 no kernel: [334682.304401@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:50 no watchdog[2624]: still alive after 325212 interval(s)
Sep 12 18:46:51 no watchdog[2624]: still alive after 325213 interval(s)
Sep 12 18:46:52 no watchdog[2624]: still alive after 325214 interval(s)
Sep 12 18:46:53 no kernel: [334685.280272@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=53
Sep 12 18:46:53 no kernel: [334685.792250@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:53 no watchdog[2624]: still alive after 325215 interval(s)
Sep 12 18:46:54 no kernel: [334686.304194@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:54 no watchdog[2624]: still alive after 325216 interval(s)
Sep 12 18:46:55 no watchdog[2624]: still alive after 325217 interval(s)
Sep 12 18:46:56 no watchdog[2624]: still alive after 325218 interval(s)
Sep 12 18:46:57 no kernel: [334689.280061@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=57
Sep 12 18:46:57 no kernel: [334689.792049@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:57 no watchdog[2624]: still alive after 325219 interval(s)
Sep 12 18:46:58 no kernel: [334690.303991@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:46:58 no watchdog[2624]: still alive after 325220 interval(s)
Sep 12 18:46:59 no watchdog[2624]: still alive after 325221 interval(s)
Sep 12 18:47:00 no watchdog[2624]: still alive after 325222 interval(s)
Sep 12 18:47:01 no kernel: [334693.279855@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=01
Sep 12 18:47:01 no kernel: [334693.791843@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:01 no watchdog[2624]: still alive after 325223 interval(s)
Sep 12 18:47:02 no kernel: [334694.303793@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:02 no watchdog[2624]: still alive after 325224 interval(s)
Sep 12 18:47:03 no watchdog[2624]: still alive after 325225 interval(s)
Sep 12 18:47:04 no watchdog[2624]: still alive after 325226 interval(s)
Sep 12 18:47:05 no kernel: [334697.279671@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=05
Sep 12 18:47:05 no kernel: [334697.791646@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:05 no watchdog[2624]: still alive after 325227 interval(s)
Sep 12 18:47:06 no kernel: [334698.303592@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:06 no watchdog[2624]: still alive after 325228 interval(s)
Sep 12 18:47:07 no watchdog[2624]: still alive after 325229 interval(s)
Sep 12 18:47:08 no watchdog[2624]: still alive after 325230 interval(s)
Sep 12 18:47:09 no kernel: [334701.279471@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=09
Sep 12 18:47:09 no kernel: [334701.791435@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:09 no watchdog[2624]: still alive after 325231 interval(s)
Sep 12 18:47:10 no kernel: [334702.303381@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:10 no watchdog[2624]: still alive after 325232 interval(s)
Sep 12 18:47:11 no watchdog[2624]: still alive after 325233 interval(s)
Sep 12 18:47:12 no watchdog[2624]: still alive after 325234 interval(s)
Sep 12 18:47:13 no kernel: [334705.279275@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=13
Sep 12 18:47:13 no kernel: [334705.791230@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:13 no watchdog[2624]: still alive after 325235 interval(s)
Sep 12 18:47:14 no kernel: [334706.303180@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:14 no watchdog[2624]: still alive after 325236 interval(s)
Sep 12 18:47:15 no watchdog[2624]: still alive after 325237 interval(s)
Sep 12 18:47:16 no watchdog[2624]: still alive after 325238 interval(s)
Sep 12 18:47:17 no kernel: [334709.279063@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=17
Sep 12 18:47:17 no kernel: [334709.791021@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:17 no watchdog[2624]: still alive after 325239 interval(s)
Sep 12 18:47:18 no kernel: [334710.302983@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:18 no watchdog[2624]: still alive after 325240 interval(s)
Sep 12 18:47:19 no watchdog[2624]: still alive after 325241 interval(s)
Sep 12 18:47:20 no watchdog[2624]: still alive after 325242 interval(s)
Sep 12 18:47:21 no kernel: [334713.278862@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=21
Sep 12 18:47:21 no kernel: [334713.790816@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:21 no watchdog[2624]: still alive after 325243 interval(s)
Sep 12 18:47:22 no kernel: [334714.302789@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:22 no watchdog[2624]: still alive after 325244 interval(s)
Sep 12 18:47:23 no watchdog[2624]: still alive after 325245 interval(s)
Sep 12 18:47:24 no watchdog[2624]: still alive after 325246 interval(s)
Sep 12 18:47:25 no kernel: [334717.278668@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=25
Sep 12 18:47:25 no kernel: [334717.790601@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:25 no watchdog[2624]: still alive after 325247 interval(s)
Sep 12 18:47:26 no kernel: [334718.302575@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:26 no watchdog[2624]: still alive after 325248 interval(s)
Sep 12 18:47:27 no watchdog[2624]: still alive after 325249 interval(s)
Sep 12 18:47:28 no watchdog[2624]: still alive after 325250 interval(s)
Sep 12 18:47:29 no kernel: [334721.278461@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=29
Sep 12 18:47:29 no kernel: [334721.790430@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:29 no watchdog[2624]: still alive after 325251 interval(s)
Sep 12 18:47:30 no kernel: [334722.302375@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:30 no watchdog[2624]: still alive after 325252 interval(s)
Sep 12 18:47:31 no watchdog[2624]: still alive after 325253 interval(s)
Sep 12 18:47:32 no watchdog[2624]: still alive after 325254 interval(s)
Sep 12 18:47:33 no kernel: [334725.278251@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=33
Sep 12 18:47:33 no kernel: [334725.790229@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:34 no watchdog[2624]: still alive after 325255 interval(s)
Sep 12 18:47:34 no kernel: [334726.302178@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:35 no watchdog[2624]: still alive after 325256 interval(s)
Sep 12 18:47:36 no watchdog[2624]: still alive after 325257 interval(s)
Sep 12 18:47:37 no kernel: [334729.278042@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=37
Sep 12 18:47:37 no kernel: [334729.790025@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:37 no watchdog[2624]: still alive after 325258 interval(s)
Sep 12 18:47:38 no kernel: [334730.301968@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:39 no watchdog[2624]: still alive after 325259 interval(s)
Sep 12 18:47:40 no watchdog[2624]: still alive after 325260 interval(s)
Sep 12 18:47:41 no kernel: [334733.277827@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=41
Sep 12 18:47:41 no watchdog[2624]: still alive after 325261 interval(s)
Sep 12 18:47:41 no kernel: [334733.789825@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:42 no kernel: [334734.301764@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:42 no watchdog[2624]: still alive after 325262 interval(s)
Sep 12 18:47:43 no watchdog[2624]: still alive after 325263 interval(s)
Sep 12 18:47:44 no watchdog[2624]: still alive after 325264 interval(s)
Sep 12 18:47:45 no kernel: [334737.277623@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=45
Sep 12 18:47:45 no watchdog[2624]: still alive after 325265 interval(s)
Sep 12 18:47:45 no kernel: [334737.789601@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:46 no kernel: [334738.301561@4] rtc-pcf8563 3-0051: pcf8563_read_block_data: read error
Sep 12 18:47:46 no watchdog[2624]: still alive after 325266 interval(s)
Sep 12 18:47:47 no watchdog[2624]: still alive after 325267 interval(s)
Sep 12 18:47:48 no watchdog[2624]: still alive after 325268 interval(s)
Sep 12 18:47:49 no kernel: [334741.277444@4] rtc-pcf8563 3-0051: pcf8563_write_block_data: err=-110 addr=02, data=49
Sep 12 18:47:49 no watchdog[2624]: still alive after 325269 interval(s)
First NetworkManager reports that eth0 has lost its connection. Then ntp finds that it cannot connect to any time server since there is no network connection. My suspicion is that then the rtc is called but it fails now since I have disabled the i2c bus that it is on.

So in the end the real culprit seems to be NetworkManager, which is an enabled service by default on the N2. Why does it report that the connection is lost? The N2 is connected directly from its ethernet port to an ethernet port on router acting as an access point. The connection is made by DHCP, the default for N2. Nothing was physically touched either before or after NetworkManager detected the lost connection and then reconnected. Simply doing "killall datacoll" got datacoll going again with no physical changes.

For this particular N2 the networking needs are very simple: hardwired ethernet directly to the access point only about 30cm away, no need for WiFi, no need for hot-plugging, no need for DHCP either really.

I would like to try running the N2 with a static ip address, but with the latest minimal image and Ubuntu 18.0.4 I am not sure exactly how to accomplish it. The old network interfaces is gone:

Code: Select all

root@no:/home/d# cat /etc/network/interfaces
# ifupdown has been replaced by netplan(5) on this system.  See
# /etc/netplan for current configuration.
# To re-enable ifupdown on this system, you can run:
#    sudo apt install ifupdown
and the replacement netplan seems empty:

Code: Select all

root@no:/home/d# ls -l /etc/netplan
total 0
root@no:/home/d# ls -l /etc|grep netplan
drwxr-xr-x 2 root root     4096 Jul  5  2018 netplan
Research on the internet suggests that netctl or dhcpcd may be better alternatives than NetworkManager but I suspect from the age of the comments they may not be available now. Certainly neither one was listed as an enabled service on the N2:

Code: Select all

root@normaddieiin2:/home/daco# systemctl list-unit-files --state=enabled
UNIT FILE                                  STATE  
ntp-systemd-netif.path                     enabled
atd.service                                enabled
autovt@.service                            enabled
console-setup.service                      enabled
cron.service                               enabled
datacoll.service                           enabled
dbus-fi.w1.wpa_supplicant1.service         enabled
dbus-org.freedesktop.ModemManager1.service enabled
dbus-org.freedesktop.nm-dispatcher.service enabled
dbus-org.freedesktop.resolve1.service      enabled
getty@.service                             enabled
keyboard-setup.service                     enabled
mariadb.service                            enabled
ModemManager.service                       enabled
mysql.service                              enabled
mysqld.service                             enabled
network-manager.service                    enabled
networkd-dispatcher.service                enabled
NetworkManager-dispatcher.service          enabled
NetworkManager-wait-online.service         enabled
NetworkManager.service                     enabled
nginx.service                              enabled
ntp.service                                enabled
odroid-tweaks.service                      enabled
ondemand.service                           enabled
php7.2-fpm.service                         enabled
pppd-dns.service                           enabled
pwm-ctrl.service                           enabled
rsync.service                              enabled
rsyslog.service                            enabled
setpullups.service                         enabled
setvtrgb.service                           enabled
ssh.service                                enabled
sshd.service                               enabled
syslog.service                             enabled
systemd-resolved.service                   enabled
systemd-timesyncd.service                  enabled
ufw.service                                enabled
watchdog.service                           enabled
wpa_supplicant.service                     enabled
remote-fs.target                           enabled
apt-daily-upgrade.timer                    enabled
apt-daily.timer                            enabled
fstrim.timer                               enabled
motd-news.timer                            enabled
phpsessionclean.timer                      enabled

46 unit files listed.
I understand that HK has some much bigger and more important issues at hand, but I would really appreciate some guidance on how to implement my very simple needs.

Thanks.

User avatar
mad_ady
Posts: 6796
Joined: Wed Jul 15, 2015 5:00 pm
languages_spoken: english
ODROIDs: XU4, C1+, C2, N1, H2, N2
Location: Bucharest, Romania
Has thanked: 216 times
Been thanked: 166 times
Contact:

Re: Problems with ntp and rtc

Unread post by mad_ady » Sat Sep 14, 2019 7:02 pm

You can try nmtui to set up a static address with network manager, from cli.
These users thanked the author mad_ady for the post:
paulcrawford (Sat Sep 14, 2019 8:05 pm)

User avatar
odroid
Site Admin
Posts: 32552
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID
Has thanked: 189 times
Been thanked: 352 times
Contact:

Re: Problems with ntp and rtc

Unread post by odroid » Mon Sep 16, 2019 4:06 pm

Your issue seems to be caused by uncertain network disconnection problem as you investigated.
I hope the static IP approach can be an acceptable workaround.

paulcrawford
Posts: 160
Joined: Tue May 10, 2016 11:51 am
languages_spoken: english
ODROIDs: c2 and n2
Has thanked: 19 times
Been thanked: 4 times
Contact:

Re: Problems with ntp and rtc

Unread post by paulcrawford » Tue Nov 05, 2019 12:14 am

I too had hoped that the static ip address setting would prevent any further issues but last night it occurred twice.

Here is the syslog entry for the first instance:

Code: Select all

Nov  4 03:30:56 no kernel: [19122.153486@5] meson6-dwmac ff3f0000.ethernet eth0: Link is Down
Nov  4 03:30:56 no datacoll[2399]: badcrc wj28-r[0]: 95, [1]: 6b, [2]: 5b, [3]: db, [4]: 9b, [5]: 37, [6]: 76, [7]: e6, [8]: e7, [9]: ce, [10]: ff, [11]: ff, [12]: ff, [13]: ff, [14]: ff, [15]: ff, [16]: ff, [17]: ffonly 1 bytes read on wnc
Nov  4 03:31:02 no NetworkManager[2219]: <info>  [1572856262.5799] device (eth0): state change: activated -> unavailable (reason 'carrier-changed', sys-iface-state: 'managed')
Nov  4 03:31:02 no NetworkManager[2219]: <info>  [1572856262.5856] manager: NetworkManager state is now CONNECTED_SITE
Nov  4 03:31:02 no dbus-daemon[2215]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=2219 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Nov  4 03:31:02 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov  4 03:31:02 no NetworkManager[2219]: <info>  [1572856262.6163] manager: NetworkManager state is now CONNECTED_LOCAL
Nov  4 03:31:02 no NetworkManager[2219]: <info>  [1572856262.6221] manager: NetworkManager state is now DISCONNECTED
Nov  4 03:31:02 no dbus-daemon[2215]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov  4 03:31:02 no systemd[1]: Started Network Manager Script Dispatcher Service.
Nov  4 03:31:02 no nm-dispatcher: req:1 'connectivity-change': new request (2 scripts)
Nov  4 03:31:02 no nm-dispatcher: req:1 'connectivity-change': start running ordered scripts...
Nov  4 03:31:02 no nm-dispatcher: req:2 'down' [eth0]: new request (2 scripts)
Nov  4 03:31:02 no nm-dispatcher: req:2 'down' [eth0]: start running ordered scripts...
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5282] device (eth0): carrier: link connected
Nov  4 03:31:37 no kernel: [19163.111523@5] meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5337] device (eth0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5415] policy: auto-activating connection 'Wired connection 1'
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5494] device (eth0): Activation: starting connection 'Wired connection 1' (d19dbcdd-02e7-3a28-ad6c-c292c1033b0a)
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5536] device (eth0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5566] manager: NetworkManager state is now CONNECTING
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5629] device (eth0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5668] device (eth0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5828] device (eth0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5888] device (eth0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5897] device (eth0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5902] manager: NetworkManager state is now CONNECTED_LOCAL
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5950] manager: NetworkManager state is now CONNECTED_SITE
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5954] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.5968] device (eth0): Activation: successful, device activated.
Nov  4 03:31:37 no NetworkManager[2219]: <info>  [1572856297.6001] manager: NetworkManager state is now CONNECTED_GLOBAL
Nov  4 03:31:37 no dbus-daemon[2215]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=2219 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Nov  4 03:31:37 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov  4 03:31:37 no dbus-daemon[2215]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov  4 03:31:37 no systemd[1]: Started Network Manager Script Dispatcher Service.
Nov  4 03:31:37 no nm-dispatcher: req:1 'up' [eth0]: new request (2 scripts)
Nov  4 03:31:37 no nm-dispatcher: req:1 'up' [eth0]: start running ordered scripts...
Nov  4 03:31:37 no nm-dispatcher: req:2 'connectivity-change': new request (2 scripts)
Nov  4 03:31:37 no systemd[1]: Reloading OpenBSD Secure Shell server.
Nov  4 03:31:37 no nm-dispatcher: req:2 'connectivity-change': start running ordered scripts...
Nov  4 03:31:37 no systemd[1]: Reloaded OpenBSD Secure Shell server.
Nov  4 03:31:47 no systemd-resolved[2198]: Using degraded feature set (UDP) for DNS server 192.168.10.1.
Nov  4 03:31:49 no ntpdate[4155]: name server cannot be used: Temporary failure in name resolution (-3)
Nov  4 03:39:01 no CRON[4175]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Nov  4 03:39:03 no systemd[1]: Starting Clean php session files...
Nov  4 03:39:04 no systemd[1]: Started Clean php session files.
About an hour and half later a similar, if not identical, occurrence:

Code: Select all

Nov  4 05:12:39 no kernel: [25224.897625@5] meson6-dwmac ff3f0000.ethernet eth0: Link is Down
Nov  4 05:12:40 no datacoll[2399]: only 1 bytes read on wnc
Nov  4 05:12:45 no NetworkManager[2219]: <info>  [1572862365.6161] device (eth0): state change: activated -> unavailable (reason 'carrier-changed', sys-iface-state: 'managed')
Nov  4 05:12:45 no NetworkManager[2219]: <info>  [1572862365.6217] manager: NetworkManager state is now CONNECTED_SITE
Nov  4 05:12:45 no dbus-daemon[2215]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=2219 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Nov  4 05:12:45 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov  4 05:12:45 no NetworkManager[2219]: <info>  [1572862365.6501] manager: NetworkManager state is now CONNECTED_LOCAL
Nov  4 05:12:45 no NetworkManager[2219]: <info>  [1572862365.6523] manager: NetworkManager state is now DISCONNECTED
Nov  4 05:12:45 no dbus-daemon[2215]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov  4 05:12:45 no systemd[1]: Started Network Manager Script Dispatcher Service.
Nov  4 05:12:45 no nm-dispatcher: req:1 'connectivity-change': new request (2 scripts)
Nov  4 05:12:45 no nm-dispatcher: req:1 'connectivity-change': start running ordered scripts...
Nov  4 05:12:45 no nm-dispatcher: req:2 'down' [eth0]: new request (2 scripts)
Nov  4 05:12:45 no nm-dispatcher: req:2 'down' [eth0]: start running ordered scripts...
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.5922] device (eth0): carrier: link connected
Nov  4 05:13:21 no kernel: [25266.879668@5] meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.5969] device (eth0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6009] policy: auto-activating connection 'Wired connection 1'
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6135] device (eth0): Activation: starting connection 'Wired connection 1' (d19dbcdd-02e7-3a28-ad6c-c292c1033b0a)
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6165] device (eth0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6188] manager: NetworkManager state is now CONNECTING
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6239] device (eth0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6278] device (eth0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6446] device (eth0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6507] device (eth0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6520] device (eth0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6528] manager: NetworkManager state is now CONNECTED_LOCAL
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6587] manager: NetworkManager state is now CONNECTED_SITE
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6591] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6607] device (eth0): Activation: successful, device activated.
Nov  4 05:13:21 no NetworkManager[2219]: <info>  [1572862401.6656] manager: NetworkManager state is now CONNECTED_GLOBAL
Nov  4 05:13:21 no dbus-daemon[2215]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=2219 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel")
Nov  4 05:13:21 no systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov  4 05:13:21 no dbus-daemon[2215]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov  4 05:13:21 no systemd[1]: Started Network Manager Script Dispatcher Service.
Nov  4 05:13:21 no nm-dispatcher: req:1 'up' [eth0]: new request (2 scripts)
Nov  4 05:13:21 no nm-dispatcher: req:1 'up' [eth0]: start running ordered scripts...
Nov  4 05:13:21 no nm-dispatcher: req:2 'connectivity-change': new request (2 scripts)
Nov  4 05:13:21 no systemd[1]: Reloading OpenBSD Secure Shell server.
Nov  4 05:13:21 no nm-dispatcher: req:2 'connectivity-change': start running ordered scripts...
Nov  4 05:13:21 no systemd[1]: Reloaded OpenBSD Secure Shell server.
Nov  4 05:13:31 no systemd-resolved[2198]: Using degraded feature set (UDP) for DNS server 192.168.10.1.
Nov  4 05:13:32 no ntpdate[4553]: name server cannot be used: Temporary failure in name resolution (-3)
I do not have enough knowledge of how or why this ethernet connection loss occurred and what part, if any, NetworkManager plays in this.

Could anyone with more knowledge please share it?

Thanks.

User avatar
mad_ady
Posts: 6796
Joined: Wed Jul 15, 2015 5:00 pm
languages_spoken: english
ODROIDs: XU4, C1+, C2, N1, H2, N2
Location: Bucharest, Romania
Has thanked: 216 times
Been thanked: 166 times
Contact:

Re: Problems with ntp and rtc

Unread post by mad_ady » Tue Nov 05, 2019 1:35 am

The cause is reported as reason 'carrier-changed.
The cause can be:
* faulty cable
* faulty rj45 jsck
* faulty rj45 port/socket
* extreme interference along the cable path.

The no-carrier is usually caused by something electrical.
These users thanked the author mad_ady for the post:
paulcrawford (Tue Nov 05, 2019 2:23 am)

Post Reply

Return to “Issues”

Who is online

Users browsing this forum: No registered users and 6 guests