[2/4] impala git commit: KUDU-2270: Add a flag to control logging in RpczStore::LogTrace()

[ta...@apache.org]

KUDU-2270: Add a flag to control logging in RpczStore::LogTrace()

This change adds a new flag FLAGS_rpc_duration_too_long_ms
which controls the duration above which a RPC is considered
too long and is logged at INFO level in the log. Previously,
this threshold is hardcoded to 1000ms which may be too short
for a busy Impalad demon, leading to massive log spew.

Change-Id: Ie587ee602e83bb65d74f7ee622a9bc47897f2574
Reviewed-on: http://gerrit.cloudera.org:8080/9117
Reviewed-by: Todd Lipcon <to...@apache.org>
Tested-by: Kudu Jenkins
Reviewed-on: http://gerrit.cloudera.org:8080/9121
Reviewed-by: Lars Volker <lv...@cloudera.com>
Tested-by: Impala Public Jenkins


Project: http://git-wip-us.apache.org/repos/asf/impala/repo
Commit: http://git-wip-us.apache.org/repos/asf/impala/commit/b08e6eb4
Tree: http://git-wip-us.apache.org/repos/asf/impala/tree/b08e6eb4
Diff: http://git-wip-us.apache.org/repos/asf/impala/diff/b08e6eb4

Branch: refs/heads/2.x
Commit: b08e6eb4f36f3dccfc409dd3804e4fbe3fe57acd
Parents: c0c3ba7
Author: Michael Ho <kw...@cloudera.com>
Authored: Wed Jan 24 00:05:11 2018 -0800
Committer: Philip Zeyliger <ph...@cloudera.com>
Committed: Thu Jan 25 16:30:18 2018 -0800

----------------------------------------------------------------------
 be/src/kudu/rpc/rpc-test.cc   | 1 +
 be/src/kudu/rpc/rpcz_store.cc | 9 ++++++++-
 2 files changed, 9 insertions(+), 1 deletion(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/impala/blob/b08e6eb4/be/src/kudu/rpc/rpc-test.cc
----------------------------------------------------------------------
diff --git a/be/src/kudu/rpc/rpc-test.cc b/be/src/kudu/rpc/rpc-test.cc
index dc29323..6d9d156 100644
--- a/be/src/kudu/rpc/rpc-test.cc
+++ b/be/src/kudu/rpc/rpc-test.cc
@@ -43,6 +43,7 @@ METRIC_DECLARE_histogram(rpc_incoming_queue_time);
 
 DECLARE_bool(rpc_reopen_outbound_connections);
 DECLARE_int32(rpc_negotiation_inject_delay_ms);
+DECLARE_int32(rpc_duration_too_long_ms);
 
 using std::shared_ptr;
 using std::string;

http://git-wip-us.apache.org/repos/asf/impala/blob/b08e6eb4/be/src/kudu/rpc/rpcz_store.cc
----------------------------------------------------------------------
diff --git a/be/src/kudu/rpc/rpcz_store.cc b/be/src/kudu/rpc/rpcz_store.cc
index b1a0591..710a57e 100644
--- a/be/src/kudu/rpc/rpcz_store.cc
+++ b/be/src/kudu/rpc/rpcz_store.cc
@@ -40,6 +40,13 @@ DEFINE_bool_hidden(rpc_dump_all_traces, false,
 TAG_FLAG(rpc_dump_all_traces, advanced);
 TAG_FLAG(rpc_dump_all_traces, runtime);
 
+DEFINE_int32_hidden(rpc_duration_too_long_ms, 1000,
+             "Threshold (in milliseconds) above which a RPC is considered too long and its "
+             "duration and method name are logged at INFO level. The time measured is between "
+             "when a RPC is accepted and when its call handler completes.");
+TAG_FLAG(rpc_duration_too_long_ms, advanced);
+TAG_FLAG(rpc_duration_too_long_ms, runtime);
+
 using std::pair;
 using std::vector;
 using std::unique_ptr;
@@ -244,7 +251,7 @@ void RpczStore::LogTrace(InboundCall* call) {
   if (PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
     LOG(INFO) << call->ToString() << " took " << duration_ms << "ms. Trace:";
     call->trace()->Dump(&LOG(INFO), true);
-  } else if (duration_ms > 1000) {
+  } else if (duration_ms > FLAGS_rpc_duration_too_long_ms) {
     LOG(INFO) << call->ToString() << " took " << duration_ms << "ms. "
               << "Request Metrics: " << call->trace()->MetricsAsJSON();
   }