This is an automated email from the ASF dual-hosted git repository. laszlog pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/impala.git
commit 72cc1bccbf3a2de8b4b17f77af9223a96e22fa11 Author: Riza Suminto <[email protected]> AuthorDate: Thu Oct 5 09:26:44 2023 -0700 IMPALA-12482: Make VLOG level of RpcEventHandler adjustable Not all RPC need to print logs at VLOG level 2. For example, StatestoreSubscriber.UpdateState is a periodic RPC that happens every 1 second. Debugging impalad through lowering VLOG lovel to 2 has been difficult due to noise from this StatestoreSubscriber.UpdateState RPC that buries other more important log lines. This patch add vlog_level parameter in RpcEventHandler to make log level for different kind of RPC adjustable. Testing: - Manually test that log lines from StatestoreSubscriber.UpdateState is not printed anymore after lowering backend VLOG level to 2. Change-Id: Ic7658ee0016411a9ace0ca3f2eb535b03d2a7add Reviewed-on: http://gerrit.cloudera.org:8080/20537 Reviewed-by: Wenzhe Zhou <[email protected]> Reviewed-by: Michael Smith <[email protected]> Tested-by: Impala Public Jenkins <[email protected]> --- be/src/rpc/rpc-trace.cc | 17 ++++++++++------- be/src/rpc/rpc-trace.h | 7 ++++++- be/src/statestore/statestore-subscriber.cc | 4 +++- 3 files changed, 19 insertions(+), 9 deletions(-) diff --git a/be/src/rpc/rpc-trace.cc b/be/src/rpc/rpc-trace.cc index 0b487c361..146e78f8d 100644 --- a/be/src/rpc/rpc-trace.cc +++ b/be/src/rpc/rpc-trace.cc @@ -157,8 +157,9 @@ void RpcEventHandler::ResetAll() { } } -RpcEventHandler::RpcEventHandler(const string& server_name, MetricGroup* metrics) : - server_name_(server_name), metrics_(metrics) { +RpcEventHandler::RpcEventHandler( + const string& server_name, MetricGroup* metrics, int vlog_level) + : server_name_(server_name), metrics_(metrics), vlog_level_(vlog_level) { if (handler_manager.get() != nullptr) handler_manager->RegisterEventHandler(this); } @@ -233,8 +234,9 @@ void* RpcEventHandler::getContext(const char* fn_name, void* server_context) { InvocationContext* ctxt_ptr = new InvocationContext(GetMonoTimeMicros(), cnxn_ctx, it->second); SetThreadRPCContext(ctxt_ptr); - VLOG_RPC << "RPC call: " << string(fn_name) << "(from " - << TNetworkAddressToString(ctxt_ptr->cnxn_ctx->network_address) << ")"; + VLOG(vlog_level_) << "RPC call: " << string(fn_name) << "(from " + << TNetworkAddressToString(ctxt_ptr->cnxn_ctx->network_address) + << ")"; return reinterpret_cast<void*>(ctxt_ptr); } @@ -253,9 +255,10 @@ void RpcEventHandler::postWrite(void* ctx, const char* fn_name, uint32_t bytes) const int64_t write_time = rpc_ctx->write_end_us - rpc_ctx->write_start_us; const string& call_name = string(fn_name); // TODO: bytes is always 0 since TTransport does not track write count. - VLOG_RPC << "RPC call: " << server_name_ << ":" << call_name << " from " - << TNetworkAddressToString(rpc_ctx->cnxn_ctx->network_address) << " took " - << PrettyPrinter::Print(elapsed_time * 1000L, TUnit::TIME_NS); + VLOG(vlog_level_) << "RPC call: " << server_name_ << ":" << call_name << " from " + << TNetworkAddressToString(rpc_ctx->cnxn_ctx->network_address) + << " took " + << PrettyPrinter::Print(elapsed_time * 1000L, TUnit::TIME_NS); MethodDescriptor* descriptor = rpc_ctx->method_descriptor; descriptor->num_in_flight.Add(-1); descriptor->processing_time_distribution->Update(elapsed_time); diff --git a/be/src/rpc/rpc-trace.h b/be/src/rpc/rpc-trace.h index f896d8370..f82cd7f0d 100644 --- a/be/src/rpc/rpc-trace.h +++ b/be/src/rpc/rpc-trace.h @@ -69,8 +69,13 @@ class RpcEventHandler : public apache::thrift::TProcessorEventHandler { /// Metrics subsystem access MetricGroup* metrics_; + + /// Log level for this handler + int vlog_level_; + public: - RpcEventHandler(const std::string& server_name, MetricGroup* metrics); + RpcEventHandler( + const std::string& server_name, MetricGroup* metrics, int vlog_level = 2); /// From TProcessorEventHandler, called initially when an Rpc is invoked. Returns an /// InvocationContext*. 'server_context' is a per-connection context object. For our diff --git a/be/src/statestore/statestore-subscriber.cc b/be/src/statestore/statestore-subscriber.cc index b49e25491..78582e0e3 100644 --- a/be/src/statestore/statestore-subscriber.cc +++ b/be/src/statestore/statestore-subscriber.cc @@ -217,8 +217,10 @@ Status StatestoreSubscriber::Start() { // Backend must be started before registration std::shared_ptr<TProcessor> processor( new StatestoreSubscriberProcessor(thrift_iface_)); + // Logging statestore subscriber heartbeats at VLOG(3) to avoid overwhelming lower log + // levels. std::shared_ptr<TProcessorEventHandler> event_handler( - new RpcEventHandler("statestore-subscriber", metrics_)); + new RpcEventHandler("statestore-subscriber", metrics_, 3 /*vlog_level*/)); processor->setEventHandler(event_handler); ThriftServerBuilder builder(
