Eclipse Community Forums: Kura » ClockService very strange behaviour when network connection lost

Home » Eclipse Projects » Kura » ClockService very strange behaviour when network connection lost(possibly because of how UDP works?)

ClockService very strange behaviour when network connection lost [message #1755591]

Mon, 06 March 2017 03:07

Eclipse User

Kura 1.4.

Prior to this snippet of logs, the internet connection has been down for some time. During this time, the ClockService/AbstractNtpClockSyncProvider tries constantly to run (without any delay). I believe this is due to the retryInterval defaulting to 5 seconds, while the timeout for the UDP request must be 10 seconds. You can see that the log snippet begins at the 313th attempt.

Either way, once the network is restored, the offset is extremely incorrect - could this be because the UDP response packet was in fact in response to a request prior to the network going down?

The following synch around 35 minutes later (maybe?) tends to agree with the problematic result, returning an offset of only 1.7 seconds. It is only the subsequent sync that corrects the problem.

2017-03-05 23:42:40,847 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Try to sync clock (313)
2017-03-05 23:42:50,875 [AbstractNtpClockSyncProvider:schedule] WARN  o.e.k.l.c.JavaNtpClockSyncProvider - Error while synchronizing System Clock with NTP host 0.pool.ntp.org. Please verify network connectivity ...
2017-03-05 23:42:50,877 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Try to sync clock (314)
2017-03-05 23:43:00,905 [AbstractNtpClockSyncProvider:schedule] WARN  o.e.k.l.c.JavaNtpClockSyncProvider - Error while synchronizing System Clock with NTP host 0.pool.ntp.org. Please verify network connectivity ...
2017-03-05 23:43:00,907 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Try to sync clock (315)
2017-03-05 23:43:00,928 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - Clock update. Offset: -5667287
2017-03-05 22:08:33,202 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - System Clock Updated to Sun Mar 05 22:08:33 AEDT 2017
2017-03-05 22:08:33,424 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - Hardware Clock Updated
2017-03-05 22:08:33,427 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Clock synced
2017-03-05 22:42:17,848 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Try to sync clock (0)
2017-03-05 22:42:17,866 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - Clock update. Offset: 1745
2017-03-05 22:42:19,111 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - System Clock Updated to Sun Mar 05 22:42:19 AEDT 2017
2017-03-05 22:42:19,201 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - Hardware Clock Updated
2017-03-05 22:42:19,204 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Clock synced
2017-03-05 23:42:34,009 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Try to sync clock (0)
2017-03-05 23:42:34,051 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - Clock update. Offset: 5670907
2017-03-06 01:17:04,169 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - System Clock Updated to Mon Mar 06 01:17:04 AEDT 2017
2017-03-06 01:17:04,250 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.ClockServiceImpl - Hardware Clock Updated
2017-03-06 01:17:04,252 [AbstractNtpClockSyncProvider:schedule] INFO  o.e.k.l.c.AbstractNtpClockSyncProvider - Clock synced

Any tips on how to avoid this in future?

Re: ClockService very strange behaviour when network connection lost [message #1755621 is a reply to message #1755591]

Mon, 06 March 2017 06:26

Eclipse User

I think the implementation of org.eclipse.kura.linux.clock.JavaNtpClockSyncProvider needs to check info.getDelay() before using the result.

Quote:

InetAddress ntpHostAddr = InetAddress.getByName(m_ntpHost);
TimeInfo info = ntpClient.getTime(ntpHostAddr, m_ntpPort);
m_lastSync = new Date();
info.computeDetails();

m_listener.onClockUpdate(info.getOffset());
ret = true;

Re: ClockService very strange behaviour when network connection lost [message #1755629 is a reply to message #1755621]

Mon, 06 March 2017 06:55

Eclipse User

while you're in that class, it looks like it only closes the NTPUDPClient if there is an exception. Close should be in a finally block.

	protected boolean syncClock() throws KuraException
	{
		boolean ret = false;
		// connect and get the delta
		NTPUDPClient ntpClient = new NTPUDPClient();
        ntpClient.setDefaultTimeout(m_ntpTimeout);
        try {
            ntpClient.open();
            try {
            	InetAddress ntpHostAddr = InetAddress.getByName(m_ntpHost);
            	TimeInfo info = ntpClient.getTime(ntpHostAddr, m_ntpPort);
            	m_lastSync = new Date();
                info.computeDetails();
                
                m_listener.onClockUpdate(info.getOffset());
                ret = true;
            } catch (IOException e) {
            	ntpClient.close();
				s_logger.warn(
						"Error while synchronizing System Clock with NTP host {}. Please verify network connectivity ...",
						m_ntpHost);
            }
        } 
        catch (Exception e) {
        	throw new KuraException(KuraErrorCode.INTERNAL_ERROR, e);
        }
        return ret;
	}

Re: ClockService very strange behaviour when network connection lost [message #1755656 is a reply to message #1755629]

Mon, 06 March 2017 10:45

Eclipse User

Hi Paul,

Have you tried implementing your changes to see if they correct the issue? Not sure if you are building Kura yourself. If so, would you be interested in creating the pull request? We love getting contributions from the community!

Thanks,
--Dave

Re: ClockService very strange behaviour when network connection lost [message #1755711 is a reply to message #1755656]

Tue, 07 March 2017 02:21

Eclipse User

Hi Dave,

Sorry, I'm not set up to build/test/commit and too busy at the moment to get started, but thanks for the invite.

I'm happy to convert to issue reports for the time being.

Thanks, Paul.

https://github.com/eclipse/kura/issues/1160

Previous Topic:	MQTT Subscribe not working using DataService
Next Topic:	Using Raspberry GPIO

Goto Forum:

-=] Back to Top [=-

Current Time: Wed Jul 09 19:07:44 EDT 2025

.:: Contact :: Home ::.

Breadcrumbs

Sign up to our Newsletter