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 <[email protected]> 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 <[email protected]> Tested-by: Impala Public Jenkins <[email protected]> --- 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")
