Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Various improvements to NtpClient class #1482

Merged
merged 3 commits into from
Oct 12, 2018

Conversation

mikee47
Copy link
Contributor

@mikee47 mikee47 commented Oct 11, 2018

Tested with SystemClock_NTP sample, but note that time will be wrong as we don't yet have any timezone management in place. The sample also sets local time, but NTP provides time in UTC. No point in fixing that yet as without timezone it just makes things worse.

  • Fix #include guard name
  • Tidy #includes
  • Put NTP_DEFAULT_SERVER into Flash
  • Use const String& for parameters
  • Use SimpleTimer instead of Timer as appropriate (efficiency, saves RAM)
  • timeoutTimer doesn't need to be initialised until a request has been queued, so moved out of constructor
  • Replace staticDnsResponse() with lambda
  • Tidy extraction of timestamp from received packet using LWIP macro

Closes: #1449

* Fix #include guard name
* Tidy #includes
* Put NTP_DEFAULT_SERVER into Flash
* Use const String& for parameters
* Use SimpleTimer instead of Timer as appropriate (efficiency, saves RAM)
* timeoutTimer doesn't need to be initialised until a request has been queued, so moved out of constructor
* Replace staticDnsResponse() with lambda
* Tidy extraction of timestamp from received packet using LWIP macro
* Rewrite using one timer
* Set timer to retry on initial request, and only stop it on success or cancellation
* Add retry if bad NTP packet received
* Change int arguments to unsigned
@mikee47
Copy link
Contributor Author

mikee47 commented Oct 11, 2018

I've emulated the synchronization problem of #1449 by giving NtpClient a duff server name to start with, then letting it have the right one after a few failed calls to dns_gethostbyname. With the previous code, it didn't work, but with the latest commit this is what happens - the -5 error indicates the DNS request is in progress. I also added an extra check in InternalRequestTime in case a bad packet is received.

6658729 NtpClient::startTimer(30000)
6658847 NtpClient::requestTime()
6658919 NtpClient::startTimer(1666)
6659416 dns_gethostbyname() returned -5
6659518 DNS IP lookup in progress...
8325064 NtpClient::requestTime()
8325177 NtpClient::startTimer(1666)
8325552 dns_gethostbyname() returned -5
8325665 DNS IP lookup in progress...
9991314 NtpClient::requestTime()
9991423 NtpClient::startTimer(1666)
9991821 dns_gethostbyname() returned -5
9991934 DNS IP lookup in progress...
11657565 NtpClient::requestTime()
11657675 NtpClient::startTimer(1666)
11658069 dns_gethostbyname() returned -5
11658185 DNS IP lookup in progress...
13323814 NtpClient::requestTime()
13323929 NtpClient::startTimer(1666)
13324326 dns_gethostbyname() returned -5
13324441 DNS IP lookup in progress...
14990078 NtpClient::requestTime()
14990194 NtpClient::startTimer(1666)
14990579 dns_gethostbyname() returned -5
14990691 DNS IP lookup in progress...
pm open,type:2 0
16656346 NtpClient::requestTime()
16656489 NtpClient::startTimer(1666)
16657114 dns_gethostbyname() returned -5
16657257 DNS IP lookup in progress...
16668500 NtpClient::internalRequestTime()
16668657 UDP LocalPort: 4097
16668738 UDP connect to 85.199.214.100:123
16678502 NtpClient::onReceive(85.199.214.100:123)
16678703 NtpClient::stopTimer()
16681958 TimeManager::update(11.10.2018 23:06:23 BST), current: 12.10.2018 05:12:49 BST
16683030 TZ diff = 3600 secs
16686053 time updated? 1
16686124 Now:     11.10.2018 23:06:23 BST
16689610 Sunrise: 12.10.2018 07:20:00 BST
16696451 Sunset:  12.10.2018 18:18:00 BST
16711708 Timer 'auto' due in 69698 secs
16711820 void IOTimerList::scheduleCheck(): Next check in 268000 ms
16711968 NtpClient::startTimer(30000)


46712113 NtpClient::requestTime()
46712282 NtpClient::startTimer(1666)
46712893 dns_gethostbyname() returned -5
46713027 DNS IP lookup in progress...
46724729 NtpClient::internalRequestTime()
46724870 UDP connect to 85.199.214.100:123
46734265 NtpClient::onReceive(85.199.214.100:123)
46734481 NtpClient::stopTimer()
46737677 TimeManager::update(11.10.2018 23:06:53 BST), current: 11.10.2018 23:06:53 BST
46738760 NtpClient::startTimer(30000)



76738906 NtpClient::requestTime()
76739072 NtpClient::startTimer(1666)
76739674 dns_gethostbyname() returned -5
76739816 DNS IP lookup in progress...
76750911 NtpClient::internalRequestTime()
76751051 UDP connect to 85.199.214.100:123
76760425 NtpClient::onReceive(85.199.214.100:123)
76760682 NtpClient::stopTimer()
76763892 TimeManager::update(11.10.2018 23:07:23 BST), current: 11.10.2018 23:07:23 BST
76764974 NtpClient::startTimer(30000)

Patch for the above test using SystemClock_NTP sample:

diff --git a/samples/SystemClock_NTP/include/NtpClientDelegateDemo.h b/samples/SystemClock_NTP/include/NtpClientDelegateDemo.h
index 418234db..90b9b6fa 100644
--- a/samples/SystemClock_NTP/include/NtpClientDelegateDemo.h
+++ b/samples/SystemClock_NTP/include/NtpClientDelegateDemo.h
@@ -6,7 +6,7 @@ class ntpClientDemo
 public:
 	ntpClientDemo()
 	{
-		ntpcp = new NtpClient("pool.ntp.org", 30, NtpTimeResultDelegate(&ntpClientDemo::ntpResult, this));
+		ntpcp = new NtpClient("non-existent-server.whereareyou", 30, NtpTimeResultDelegate(&ntpClientDemo::ntpResult, this));
 	};
 
 	void ntpResult(NtpClient& client, time_t ntpTime)

diff --git a/Sming/SmingCore/Network/NtpClient.cpp b/Sming/SmingCore/Network/NtpClient.cpp
index 4dd3db4d..4dc1e8f9 100644
--- a/Sming/SmingCore/Network/NtpClient.cpp
+++ b/Sming/SmingCore/Network/NtpClient.cpp
@@ -75,6 +75,12 @@ void NtpClient::requestTime()
 	case ERR_INPROGRESS:
 		// currently finding ip, internalRequestTime() will be called when its found.
 		debug_d("DNS IP lookup in progress...");
+		{
+			static int retrytest = 5;
+			if(retrytest-- == 0)
+				server = NTP_DEFAULT_SERVER;
+		}
+
 		break;
 	default:
 		debug_d("DNS lookup error occurred.");

@slaff slaff merged commit 207b8c3 into SmingHub:develop Oct 12, 2018
@mikee47 mikee47 deleted the feature/NtpClient_improvements branch October 12, 2018 11:08
// init timer but do not start, correct interval set later below.
autoUpdateTimer.initializeMs(NTP_DEFAULT_QUERY_INTERVAL_SECONDS * 1000,
TimerDelegate(&NtpClient::requestTime, this));
debug_d("NtpClient(\"%s\", %u, 0x%08x", reqServer.c_str(), reqIntervalSeconds, delegateFunction);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@mikee47 We have a problem here. Either remove the delegateFunction parameter or replace it something like delegateFunction ? 1:0. Or cast it to an address, if that was the initial intention.

In order to reproduce the problem compile Sming with DEBUG_VERBOSE_LEVEL=3.

cd %SMING_HOME%
make dist-clean
make DEBUG_VERBOSE_LEVEL=3

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That was silly of me! I've removed the parameter, doesn't really help anyway.

@slaff slaff added the Bug label Oct 17, 2018
@slaff slaff mentioned this pull request Oct 23, 2018
4 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

NTPClient not retrying synchronization if DNS resolution fails
2 participants