[kudu] branch branch-1.11.x updated: [clock] log on CombineClocks() status only via VLOG

[al...@apache.org]

This is an automated email from the ASF dual-hosted git repository.

alexey pushed a commit to branch branch-1.11.x
in repository https://gitbox.apache.org/repos/asf/kudu.git


The following commit(s) were added to refs/heads/branch-1.11.x by this push:
     new e7cb2f1  [clock] log on CombineClocks() status only via VLOG
e7cb2f1 is described below

commit e7cb2f196d45ae443599ec6472d69d4861957e10
Author: Alexey Serbin <al...@apache.org>
AuthorDate: Fri Oct 11 10:06:06 2019 -0700

    [clock] log on CombineClocks() status only via VLOG
    
    The logs about the walltime-would-move-back outcome of
    BuiltInNtp::CombineClocks() look a bit scary, but de facto they
    are benign and of nothing irregular in case of jittery reference
    servers.  Let's output them as VLOG(1) messages.  These should
    eventually be gone once the proper clock selection algorithm is
    implemented (see KUDU-2939 for details).
    
    Change-Id: I77ba6ea37b0e94058eaab018ae4d66976f0482cd
    Reviewed-on: http://gerrit.cloudera.org:8080/14416
    Tested-by: Kudu Jenkins
    Reviewed-by: Grant Henke <gr...@apache.org>
    (cherry picked from commit 2768c156186e3da9693ddeff78a8d3206827fb88)
    Reviewed-on: http://gerrit.cloudera.org:8080/14417
    Reviewed-by: Alexey Serbin <as...@cloudera.com>
---
 src/kudu/clock/builtin_ntp.cc | 20 ++++++++------------
 1 file changed, 8 insertions(+), 12 deletions(-)

diff --git a/src/kudu/clock/builtin_ntp.cc b/src/kudu/clock/builtin_ntp.cc
index af1e93d..dd13581 100644
--- a/src/kudu/clock/builtin_ntp.cc
+++ b/src/kudu/clock/builtin_ntp.cc
@@ -919,9 +919,8 @@ void BuiltInNtp::RecordResponse(ServerState* from_server,
   //                  dispersion of samples increasing as described in
   //                  https://tools.ietf.org/html/rfc5905 A.5.2. clock_filter()
   const auto s = CombineClocks();
-  if (!s.ok()) {
-    KLOG_EVERY_N_SECS(INFO, 60)
-        << Substitute("combining reference clocks failed: $0", s.ToString());
+  if (!s.ok() && VLOG_IS_ON(1)) {
+    VLOG(1) << Substitute("combining clocks failed: $0", s.ToString());
   }
 }
 
@@ -1027,15 +1026,12 @@ Status BuiltInNtp::CombineClocks() {
     // Extra sanity check to make sure walltime doesn't go back.
     std::lock_guard<rw_spinlock> l(last_computed_lock_);
     if (last_computed_.wall > compute_wall) {
-      auto msg = Substitute("walltime would move into past: "
-                            "current walltime $0, last walltime $1, "
-                            "current mono $2, last mono $3, "
-                            "current error $4, last error $5",
-                            compute_wall, last_computed_.wall,
-                            now, last_computed_.mono,
-                            compute_error, last_computed_.error);
-      VLOG(1) << msg;
-      return Status::IllegalState(msg);
+      return Status::IllegalState(Substitute(
+          "walltime would move into past: "
+          "current walltime $0, last walltime $1, "
+          "current mono $2, last mono $3, current error $4, last error $5",
+          compute_wall, last_computed_.wall,
+          now, last_computed_.mono, compute_error, last_computed_.error));
     }
     last_computed_.is_synchronized = true;
     last_computed_.mono = now;