You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@impala.apache.org by bo...@apache.org on 2024/11/22 14:39:29 UTC
(impala) 02/04: IMPALA-13556: Log GetRuntimeProfile and GetExecSummary at VLOG_QUERY
This is an automated email from the ASF dual-hosted git repository.
boroknagyz pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/impala.git
commit aac375eb200c32a11b94e1e0d986a74737d0636e
Author: Riza Suminto <ri...@cloudera.com>
AuthorDate: Tue Nov 19 15:18:44 2024 -0800
IMPALA-13556: Log GetRuntimeProfile and GetExecSummary at VLOG_QUERY
Calls to both of these RPC endpoints are previously logged at
VLOG_RPC (or VLOG(2)). This patch change the log level to VLOG_QUERY (or
VLOG(1)). This is helpful because both RPC are usually called after
query execution complete, but the query handle is not released yet. They
are also rarely called by client, so they will not be too noisy. Missing
query driver log in GetAllQueryHandles is moved to its caller, where the
log message is clarified.
ImpalaShell._execute_stmt() also modified to call get_runtime_profile()
only if show_profile option is true.
Testing:
- Using impala-shell, run a TPC-DS query followed by 'profile' and
summary command. Verify that logs are printed, both with beeswax and
HS2 protocol.
- Pass core tests.
Change-Id: I90ef7d0fadd81c58ec1072e53430f51fea146cf1
Reviewed-on: http://gerrit.cloudera.org:8080/22085
Reviewed-by: Impala Public Jenkins <im...@cloudera.com>
Tested-by: Impala Public Jenkins <im...@cloudera.com>
---
be/src/service/impala-beeswax-server.cc | 4 ++--
be/src/service/impala-hs2-server.cc | 4 +++-
be/src/service/impala-server.cc | 13 ++++++++++---
shell/impala_shell.py | 4 +---
4 files changed, 16 insertions(+), 9 deletions(-)
diff --git a/be/src/service/impala-beeswax-server.cc b/be/src/service/impala-beeswax-server.cc
index ac65b4384..15d907119 100644
--- a/be/src/service/impala-beeswax-server.cc
+++ b/be/src/service/impala-beeswax-server.cc
@@ -487,7 +487,7 @@ void ImpalaServer::GetRuntimeProfile(
TUniqueId query_id;
BeeswaxHandleToTUniqueId(beeswax_handle, &query_id);
- VLOG_RPC << "GetRuntimeProfile(): query_id=" << PrintId(query_id);
+ VLOG_QUERY << "GetRuntimeProfile(): query_id=" << PrintId(query_id);
// Make query id available to the following RaiseBeeswaxException().
ScopedThreadContext scoped_tdi(GetThreadDebugInfo(), query_id);
@@ -526,7 +526,7 @@ void ImpalaServer::GetExecSummary(impala::TExecSummary& result,
}
TUniqueId query_id;
BeeswaxHandleToTUniqueId(beeswax_handle, &query_id);
- VLOG_RPC << "GetExecSummary(): query_id=" << PrintId(query_id);
+ VLOG_QUERY << "GetExecSummary(): query_id=" << PrintId(query_id);
// Make query id available to the following RaiseBeeswaxException().
ScopedThreadContext scoped_tdi(GetThreadDebugInfo(), query_id);
diff --git a/be/src/service/impala-hs2-server.cc b/be/src/service/impala-hs2-server.cc
index aa829834d..33366195a 100644
--- a/be/src/service/impala-hs2-server.cc
+++ b/be/src/service/impala-hs2-server.cc
@@ -1210,6 +1210,8 @@ void ImpalaServer::GetExecSummary(TGetExecSummaryResp& return_val,
request.operationHandle.operationId, &query_id, &op_secret),
SQLSTATE_GENERAL_ERROR);
+ VLOG_QUERY << "GetExecSummary(): query_id=" << PrintId(query_id);
+
// Make query id available to the following HS2_RETURN_IF_ERROR().
ScopedThreadContext scoped_tdi(GetThreadDebugInfo(), query_id);
@@ -1297,7 +1299,7 @@ void ImpalaServer::GetRuntimeProfile(
request.operationHandle.operationId, &query_id, &op_secret),
SQLSTATE_GENERAL_ERROR);
- VLOG_RPC << "GetRuntimeProfile(): query_id=" << PrintId(query_id);
+ VLOG_QUERY << "GetRuntimeProfile(): query_id=" << PrintId(query_id);
// Make query id available to the following HS2_RETURN_IF_ERROR().
ScopedThreadContext scoped_tdi(GetThreadDebugInfo(), query_id);
diff --git a/be/src/service/impala-server.cc b/be/src/service/impala-server.cc
index 754d66563..30b4c2482 100644
--- a/be/src/service/impala-server.cc
+++ b/be/src/service/impala-server.cc
@@ -473,6 +473,11 @@ const int64_t EXPIRATION_CHECK_INTERVAL_MS = 1000L;
// TODO: this should be turned into a proper error code and used throughout ImpalaServer.
static const char* LEGACY_INVALID_QUERY_HANDLE_TEMPLATE = "Query id $0 not found.";
+// Log template for GetExecSummary and GetRuntimeProfileOutput when active query driver
+// is not found.
+static const char* INACTIVE_QUERY_DRIVER_TEMPLATE =
+ "Unable to find active query driver: $0. Continuing search at query log.";
+
ThreadSafeRandom ImpalaServer::rng_(GetRandomSeed32());
ImpalaServer::ImpalaServer(ExecEnv* exec_env)
@@ -831,6 +836,8 @@ Status ImpalaServer::GetRuntimeProfileOutput(const TUniqueId& query_id,
RETURN_IF_ERROR(
GetRuntimeProfileOutput(user, original_query_handle, format, original_profile));
return Status::OK();
+ } else {
+ VLOG_QUERY << Substitute(INACTIVE_QUERY_DRIVER_TEMPLATE, status.GetDetail());
}
}
@@ -1040,6 +1047,8 @@ Status ImpalaServer::GetExecSummary(const TUniqueId& query_id, const string& use
}
}
return Status::OK();
+ } else {
+ VLOG_QUERY << Substitute(INACTIVE_QUERY_DRIVER_TEMPLATE, status.GetDetail());
}
}
@@ -1771,9 +1780,7 @@ Status ImpalaServer::GetAllQueryHandles(const TUniqueId& query_id,
DCHECK(original_query_handle != nullptr);
shared_ptr<QueryDriver> query_driver = GetQueryDriver(query_id, return_unregistered);
if (UNLIKELY(query_driver == nullptr)) {
- Status err = Status::Expected(TErrorCode::INVALID_QUERY_HANDLE, PrintId(query_id));
- VLOG(1) << err.GetDetail();
- return err;
+ return Status::Expected(TErrorCode::INVALID_QUERY_HANDLE, PrintId(query_id));
}
active_query_handle->SetHandle(query_driver,
query_driver->GetActiveClientRequestState());
diff --git a/shell/impala_shell.py b/shell/impala_shell.py
index afea9e3d2..f4adff452 100755
--- a/shell/impala_shell.py
+++ b/shell/impala_shell.py
@@ -1460,12 +1460,10 @@ class ImpalaShell(cmd.Cmd, object):
if not is_dml:
self.imp_client.close_query(self.last_query_handle)
- try:
+ if self.show_profiles:
profile, retried_profile = self.imp_client.get_runtime_profile(
self.last_query_handle)
self.print_runtime_profile(profile, retried_profile)
- except RPCException as e:
- if self.show_profiles: raise e
return CmdStatus.SUCCESS
except QueryCancelledByShellException as e:
log_exception_with_timestamp(e, "Warning", "Query Interrupted")