IMPALA-5275: Avoid printing status stack trace on hot paths Currently, creation of a Status object (non-OK and non-EXPECTED) prints the stack trace to the log. Fetching the stack trace takes a large chunk of CPU time close to 130ms and results in a significant perf hit when encountered on hot paths. Five such hot paths were identified and the following changes were made to fix it:
1. In ImpalaServer::GetExecSummary(), create Status() without holding the query_log_lock_. 2, 3 and 4. In impala::DeserializeThriftMsg<>(), PartitionedAggregationNode::CodegenUpdateTuple() and HdfsScanner::CodegenWriteCompleteTuple, use Status::Expected where appropriate. 5. In Status::MemLimitExceeded(), create Status object without printing stacktrace Change-Id: Ief083f558fba587381aa7fe8f99da279da02f1f2 Reviewed-on: http://gerrit.cloudera.org:8080/7449 Reviewed-by: Matthew Jacobs <[email protected]> Tested-by: Impala Public Jenkins Project: http://git-wip-us.apache.org/repos/asf/incubator-impala/repo Commit: http://git-wip-us.apache.org/repos/asf/incubator-impala/commit/54865c4e Tree: http://git-wip-us.apache.org/repos/asf/incubator-impala/tree/54865c4e Diff: http://git-wip-us.apache.org/repos/asf/incubator-impala/diff/54865c4e Branch: refs/heads/master Commit: 54865c4ef1a1b54bf3fcdea4de29f7aaeb9278e8 Parents: 83bfc14 Author: Bikramjeet Vig <[email protected]> Authored: Mon Jul 17 13:18:15 2017 -0700 Committer: Impala Public Jenkins <[email protected]> Committed: Fri Jul 21 01:29:24 2017 +0000 ---------------------------------------------------------------------- be/src/common/status.cc | 6 +++--- be/src/exec/hdfs-scanner.cc | 4 ++-- be/src/exec/partitioned-aggregation-node.cc | 8 ++++---- be/src/rpc/thrift-util.h | 2 +- be/src/service/impala-server.cc | 24 ++++++++++++++++++------ 5 files changed, 28 insertions(+), 16 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/54865c4e/be/src/common/status.cc ---------------------------------------------------------------------- diff --git a/be/src/common/status.cc b/be/src/common/status.cc index 1adc654..3fc2236 100644 --- a/be/src/common/status.cc +++ b/be/src/common/status.cc @@ -37,12 +37,12 @@ const Status Status::DEPRECATED_RPC(ErrorMsg::Init(TErrorCode::NOT_IMPLEMENTED_E "Deprecated RPC; please update your client")); Status Status::MemLimitExceeded() { - return Status(TErrorCode::MEM_LIMIT_EXCEEDED, "Memory limit exceeded"); + return Status(ErrorMsg(TErrorCode::MEM_LIMIT_EXCEEDED, "Memory limit exceeded"), true); } Status Status::MemLimitExceeded(const std::string& details) { - return Status(TErrorCode::MEM_LIMIT_EXCEEDED, - Substitute("Memory limit exceeded: $0", details)); + return Status(ErrorMsg(TErrorCode::MEM_LIMIT_EXCEEDED, + Substitute("Memory limit exceeded: $0", details)), true); } Status::Status(TErrorCode::type code) http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/54865c4e/be/src/exec/hdfs-scanner.cc ---------------------------------------------------------------------- diff --git a/be/src/exec/hdfs-scanner.cc b/be/src/exec/hdfs-scanner.cc index 0670f81..10e4edd 100644 --- a/be/src/exec/hdfs-scanner.cc +++ b/be/src/exec/hdfs-scanner.cc @@ -312,10 +312,10 @@ Status HdfsScanner::CodegenWriteCompleteTuple(HdfsScanNodeBase* node, for (int i = 0; i < node->materialized_slots().size(); ++i) { SlotDescriptor* slot_desc = node->materialized_slots()[i]; if (slot_desc->type().type == TYPE_TIMESTAMP) { - return Status("Timestamp not yet supported for codegen."); + return Status::Expected("Timestamp not yet supported for codegen."); } if (slot_desc->type().type == TYPE_DECIMAL) { - return Status("Decimal not yet supported for codegen."); + return Status::Expected("Decimal not yet supported for codegen."); } } http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/54865c4e/be/src/exec/partitioned-aggregation-node.cc ---------------------------------------------------------------------- diff --git a/be/src/exec/partitioned-aggregation-node.cc b/be/src/exec/partitioned-aggregation-node.cc index 7849394..7067961 100644 --- a/be/src/exec/partitioned-aggregation-node.cc +++ b/be/src/exec/partitioned-aggregation-node.cc @@ -1743,14 +1743,14 @@ Status PartitionedAggregationNode::CodegenUpdateTuple( for (const SlotDescriptor* slot_desc : intermediate_tuple_desc_->slots()) { if (slot_desc->type().type == TYPE_CHAR) { - return Status("PartitionedAggregationNode::CodegenUpdateTuple(): cannot codegen" - "CHAR in aggregations"); + return Status::Expected("PartitionedAggregationNode::CodegenUpdateTuple(): cannot " + "codegen CHAR in aggregations"); } } if (intermediate_tuple_desc_->GetLlvmStruct(codegen) == NULL) { - return Status("PartitionedAggregationNode::CodegenUpdateTuple(): failed to generate " - "intermediate tuple desc"); + return Status::Expected("PartitionedAggregationNode::CodegenUpdateTuple(): failed to" + " generate intermediate tuple desc"); } // Get the types to match the UpdateTuple signature http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/54865c4e/be/src/rpc/thrift-util.h ---------------------------------------------------------------------- diff --git a/be/src/rpc/thrift-util.h b/be/src/rpc/thrift-util.h index 96a864c..1a66286 100644 --- a/be/src/rpc/thrift-util.h +++ b/be/src/rpc/thrift-util.h @@ -126,7 +126,7 @@ Status DeserializeThriftMsg(const uint8_t* buf, uint32_t* len, bool compact, } catch (std::exception& e) { std::stringstream msg; msg << "couldn't deserialize thrift msg:\n" << e.what(); - return Status(msg.str()); + return Status::Expected(msg.str()); } catch (...) { /// TODO: Find the right exception for 0 bytes return Status("Unknown exception"); http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/54865c4e/be/src/service/impala-server.cc ---------------------------------------------------------------------- diff --git a/be/src/service/impala-server.cc b/be/src/service/impala-server.cc index cf91ba3..a26f0ab 100644 --- a/be/src/service/impala-server.cc +++ b/be/src/service/impala-server.cc @@ -658,17 +658,29 @@ Status ImpalaServer::GetExecSummary(const TUniqueId& query_id, const string& use } // Look for the query in completed query log. + // IMPALA-5275: Don't create Status while holding query_log_lock_ { - lock_guard<mutex> l(query_log_lock_); - QueryLogIndex::const_iterator query_record = query_log_index_.find(query_id); - if (query_record == query_log_index_.end()) { + string effective_user; + bool user_has_profile_access = false; + bool is_query_missing = false; + TExecSummary exec_summary; + { + lock_guard<mutex> l(query_log_lock_); + QueryLogIndex::const_iterator query_record = query_log_index_.find(query_id); + is_query_missing = query_record == query_log_index_.end(); + if (!is_query_missing) { + effective_user = query_record->second->effective_user; + user_has_profile_access = query_record->second->user_has_profile_access; + exec_summary = query_record->second->exec_summary; + } + } + if (is_query_missing) { stringstream ss; ss << "Query id " << PrintId(query_id) << " not found."; return Status(ss.str()); } - RETURN_IF_ERROR(CheckProfileAccess(user, query_record->second->effective_user, - query_record->second->user_has_profile_access)); - *result = query_record->second->exec_summary; + RETURN_IF_ERROR(CheckProfileAccess(user, effective_user, user_has_profile_access)); + *result = exec_summary; } return Status::OK(); }
