You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@kudu.apache.org by al...@apache.org on 2020/02/24 21:54:57 UTC
[kudu] branch master updated: [clock] record maximum error in
microseconds
This is an automated email from the ASF dual-hosted git repository.
alexey pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/kudu.git
The following commit(s) were added to refs/heads/master by this push:
new 3adc288 [clock] record maximum error in microseconds
3adc288 is described below
commit 3adc2882a15af4e777cb8cd0bc7785f002a9402a
Author: Alexey Serbin <al...@apache.org>
AuthorDate: Sat Feb 22 21:35:10 2020 -0800
[clock] record maximum error in microseconds
Dedicated NTP servers of AWS/EC2 cloud instances report sub-millisecond
root delay and dispersion (see below), so it makes sense to switch
true time maximum error histogram into microseconds.
In addition, as a follow-up to the recent series of patches in the
context of KUDU-3048, I also added an extra metric gauge to track
latest maximum time error computed by the built-in NTP client. I also
renamed 'builtin_ntp_walltime' into 'builtin_ntp_time' for brevity.
This is a follow-up to 7d9d7009 and 6371ffdb5.
[root@aws-centos]# chronyc sources
210 Number of sources = 1
MS Name/IP address Stratum Poll Reach LastRx Last sample
===============================================================================
^* 169.254.169.123 3 8 377 106 +1063ns[+1441ns] +/- 466us
[root@aws-centos]# chronyc tracking
Reference ID : A9FEA97B (169.254.169.123)
Stratum : 4
Ref time (UTC) : Sun Feb 23 06:59:58 2020
System time : 0.000001781 seconds slow of NTP time
Last offset : +0.000000378 seconds
RMS offset : 0.000012111 seconds
Frequency : 30.588 ppm fast
Residual freq : -0.000 ppm
Skew : 0.019 ppm
Root delay : 0.000298246 seconds
Root dispersion : 0.000397126 seconds
Update interval : 260.0 seconds
Leap status : Normal
[root@aws-centos]# chronyc ntpdata 169.254.169.123
Remote address : 169.254.169.123 (A9FEA97B)
Remote port : 123
Local address : 10.65.14.145 (0A410E91)
Leap status : Normal
Version : 4
Mode : Server
Stratum : 3
Poll interval : 8 (256 seconds)
Precision : -18 (0.000003815 seconds)
Root delay : 0.000198 seconds
Root dispersion : 0.000305 seconds
Reference ID : A9FEA97A ()
Reference time : Sun Feb 23 06:55:06 2020
Offset : +0.000014476 seconds
Peer delay : 0.000101295 seconds
Peer dispersion : 0.000003855 seconds
Response time : 0.000015916 seconds
Jitter asymmetry: +0.00
NTP tests : 111 111 1111
Interleaved : No
Authenticated : No
TX timestamping : Kernel
RX timestamping : Kernel
Total TX : 712
Total RX : 712
Total valid RX : 712
Change-Id: Idaa950fd3dff3e2a4cedbf5ae5b93b49f7b9465c
Reviewed-on: http://gerrit.cloudera.org:8080/15275
Reviewed-by: Adar Dembo <ad...@cloudera.com>
Tested-by: Kudu Jenkins
---
src/kudu/clock/builtin_ntp.cc | 32 ++++++++++++++++++++++++--------
src/kudu/clock/builtin_ntp.h | 5 ++++-
src/kudu/clock/hybrid_clock-test.cc | 25 ++++++++++++++++++-------
src/kudu/clock/hybrid_clock.cc | 6 +++---
4 files changed, 49 insertions(+), 19 deletions(-)
diff --git a/src/kudu/clock/builtin_ntp.cc b/src/kudu/clock/builtin_ntp.cc
index 1967b05..e0b74db 100644
--- a/src/kudu/clock/builtin_ntp.cc
+++ b/src/kudu/clock/builtin_ntp.cc
@@ -118,20 +118,27 @@ METRIC_DEFINE_gauge_int64(server, builtin_ntp_local_clock_delta,
"2^63-1 when true time is not tracked",
kudu::MetricLevel::kInfo);
-METRIC_DEFINE_gauge_int64(server, builtin_ntp_walltime,
- "Built-in NTP Wall-Clock Time",
+METRIC_DEFINE_gauge_int64(server, builtin_ntp_time,
+ "Built-in NTP Time",
kudu::MetricUnit::kMicroseconds,
- "Latest wall-clock time as tracked by "
+ "Latest true time as tracked by "
"built-in NTP client",
kudu::MetricLevel::kDebug);
+METRIC_DEFINE_gauge_int64(server, builtin_ntp_error,
+ "Built-in NTP Latest Maximum Time Error",
+ kudu::MetricUnit::kMicroseconds,
+ "Latest maximum time error as tracked by "
+ "built-in NTP client",
+ kudu::MetricLevel::kInfo);
+
METRIC_DEFINE_histogram(server, builtin_ntp_max_errors,
- "Built-In NTP Maximum Errors",
- kudu::MetricUnit::kMilliseconds,
+ "Built-In NTP Maximum Time Errors",
+ kudu::MetricUnit::kMicroseconds,
"Statistics on the maximum true time error computed by "
"built-in NTP client",
kudu::MetricLevel::kDebug,
- 20000, 3);
+ 10000000, 1);
using kudu::clock::internal::Interval;
using kudu::clock::internal::kIntervalNone;
@@ -1083,7 +1090,7 @@ Status BuiltInNtp::CombineClocks() {
last_computed_.error = compute_error;
// Update stats on the computed error.
- max_errors_histogram_->Increment(compute_error / 1000);
+ max_errors_histogram_->Increment(compute_error);
}
VLOG(2) << Substitute("combined clocks: $0 $1 $2",
now, compute_wall, compute_error);
@@ -1104,10 +1111,14 @@ void BuiltInNtp::RegisterMetrics(const scoped_refptr<MetricEntity>& entity) {
entity,
Bind(&BuiltInNtp::LocalClockDeltaForMetrics, Unretained(this)))->
AutoDetachToLastValue(&metric_detacher_);
- METRIC_builtin_ntp_walltime.InstantiateFunctionGauge(
+ METRIC_builtin_ntp_time.InstantiateFunctionGauge(
entity,
Bind(&BuiltInNtp::WalltimeForMetrics, Unretained(this)))->
AutoDetachToLastValue(&metric_detacher_);
+ METRIC_builtin_ntp_error.InstantiateFunctionGauge(
+ entity,
+ Bind(&BuiltInNtp::MaxErrorForMetrics, Unretained(this)))->
+ AutoDetachToLastValue(&metric_detacher_);
max_errors_histogram_ =
METRIC_builtin_ntp_max_errors.Instantiate(entity);
}
@@ -1133,5 +1144,10 @@ int64_t BuiltInNtp::WalltimeForMetrics() {
return last_computed_.wall;
}
+int64_t BuiltInNtp::MaxErrorForMetrics() {
+ shared_lock<rw_spinlock> l(last_computed_lock_);
+ return last_computed_.error;
+}
+
} // namespace clock
} // namespace kudu
diff --git a/src/kudu/clock/builtin_ntp.h b/src/kudu/clock/builtin_ntp.h
index 7b0dc8f..7667115 100644
--- a/src/kudu/clock/builtin_ntp.h
+++ b/src/kudu/clock/builtin_ntp.h
@@ -172,9 +172,12 @@ class BuiltInNtp : public TimeService {
// in milliseconds.
int64_t LocalClockDeltaForMetrics();
- // Get the latest computed wall-clock time, in microseconds.
+ // Get the latest computed true time, in microseconds.
int64_t WalltimeForMetrics();
+ // Get the latest computed maximum error from true time, in microseconds.
+ int64_t MaxErrorForMetrics();
+
Random rng_;
Socket socket_;
diff --git a/src/kudu/clock/hybrid_clock-test.cc b/src/kudu/clock/hybrid_clock-test.cc
index c857002..d0bd9f5 100644
--- a/src/kudu/clock/hybrid_clock-test.cc
+++ b/src/kudu/clock/hybrid_clock-test.cc
@@ -376,6 +376,15 @@ TEST_F(HybridClockTest, TestRideOverNtpInterruption) {
ASSERT_LT(timestamps[1].ToUint64(), timestamps[2].ToUint64());
}
+// This scenario emulates slow initialisation of the hybrid clock's underlying
+// time source while Kudu servers are busy with bootstrapping (in this
+// particular case, the time source is the built-in NTP client). During the
+// bootstrapping, the embedded web servers are flooded with requests to the
+// '/metrics' URLs. Kudu masters and tablet servers should not crash and be able
+// to start and function as expected once the time source is up and running.
+//
+// In addition, this scenario verifies the presence of time-specific metrics in
+// the data retrieved from the '/metrics' endpoint.
TEST_F(HybridClockTest, SlowClockInitialisation) {
SKIP_IF_SLOW_NOT_ALLOWED();
@@ -390,9 +399,10 @@ TEST_F(HybridClockTest, SlowClockInitialisation) {
// The PeriodicWebUIChecker needs to know the addresses which master and
// tserver embedded web servers are bound to. So, first start all the
- // processes, then stop them, and then instantiate the PeriodicWebUIChecker.
- // This way there will be requests coming to the webservers while Kudu masters
- // and tablet servers are bootstrapping.
+ // processes, then stop them, and then instantiate the PeriodicWebUIChecker
+ // passing information on the bound addresses which will be used upon next
+ // start of masters/tservers. This way there will be requests coming to the
+ // embedded web servers while Kudu servers are bootstrapping.
ExternalMiniCluster cluster(opts);
ASSERT_OK(cluster.Start());
cluster.Shutdown();
@@ -410,7 +420,7 @@ TEST_F(HybridClockTest, SlowClockInitialisation) {
ntp_server_resumer.join();
});
- // Start pounding the master and tserver's web UIs.
+ // Start pounding the master and tserver's web server.
PeriodicWebUIChecker checker(cluster, MonoDelta::FromMilliseconds(1),
"", { "/metrics" }, { "/metrics" });
@@ -424,7 +434,7 @@ TEST_F(HybridClockTest, SlowClockInitialisation) {
NO_FATALS(cluster.AssertNoCrashes());
ASSERT_OK(ntp_server_resumer_status);
- // Check for the presence of clock-related metrics.
+ // Make sure certain time-related metrics are present.
vector<string> addresses;
addresses.reserve(cluster.num_masters() + cluster.num_tablet_servers());
for (auto idx = 0; idx < cluster.num_masters(); ++idx) {
@@ -441,13 +451,14 @@ TEST_F(HybridClockTest, SlowClockInitialisation) {
faststring buf;
ASSERT_OK(c.FetchURL(strings::Substitute("http://$0/metrics", addr), &buf));
const auto str = buf.ToString();
+ ASSERT_STR_CONTAINS(str, "builtin_ntp_error");
ASSERT_STR_CONTAINS(str, "builtin_ntp_local_clock_delta");
ASSERT_STR_CONTAINS(str, "builtin_ntp_max_errors");
- ASSERT_STR_CONTAINS(str, "builtin_ntp_walltime");
- ASSERT_STR_CONTAINS(str, "hybrid_clock_max_errors");
+ ASSERT_STR_CONTAINS(str, "builtin_ntp_time");
ASSERT_STR_CONTAINS(str, "hybrid_clock_error");
ASSERT_STR_CONTAINS(str, "hybrid_clock_extrapolating");
ASSERT_STR_CONTAINS(str, "hybrid_clock_extrapolation_intervals");
+ ASSERT_STR_CONTAINS(str, "hybrid_clock_max_errors");
ASSERT_STR_CONTAINS(str, "hybrid_clock_timestamp");
}
}
diff --git a/src/kudu/clock/hybrid_clock.cc b/src/kudu/clock/hybrid_clock.cc
index 0c369fc..70ac650 100644
--- a/src/kudu/clock/hybrid_clock.cc
+++ b/src/kudu/clock/hybrid_clock.cc
@@ -185,11 +185,11 @@ METRIC_DEFINE_gauge_uint64(server, hybrid_clock_timestamp,
METRIC_DEFINE_histogram(server, hybrid_clock_max_errors,
"Hybrid Clock Maximum Errors",
- kudu::MetricUnit::kMilliseconds,
+ kudu::MetricUnit::kMicroseconds,
"The statistics on the maximum error of the underlying "
"clock",
kudu::MetricLevel::kDebug,
- 20000, 3);
+ 10000000, 1);
METRIC_DEFINE_histogram(server, hybrid_clock_extrapolation_intervals,
"Intervals of Hybrid Clock Extrapolation",
@@ -604,7 +604,7 @@ Status HybridClock::WalltimeWithError(uint64_t* now_usec, uint64_t* error_usec)
bool is_extrapolated = false;
if (PREDICT_TRUE(s.ok())) {
- max_errors_histogram_->Increment(*error_usec / 1000);
+ max_errors_histogram_->Increment(*error_usec);
// We got a good clock read. Remember this in case the clock later becomes
// unsynchronized and we need to extrapolate from here.
//