This is an automated email from the ASF dual-hosted git repository. stigahuang pushed a commit to branch branch-3.4.2 in repository https://gitbox.apache.org/repos/asf/impala.git
commit bc15ed61a61ed5bb26bdd48bb5214adb1a1e0c6e Author: stiga-huang <[email protected]> AuthorDate: Thu Jun 30 14:59:41 2022 +0800 IMPALA-11406: Fix incorrect duration log for authorization IMPALA-8443 extends EventSequence.markEvent() to return the duration between the last and the current event. However, the duration is calculated using the start time, not the last time it's invoked, which causes misleading time in logs of "Authorization check took n ms". This fixes the bug and also adds a log for the analysis duration. Change-Id: I8b665f1b4ac86577711598ce9d845cf82fedbcd7 Reviewed-on: http://gerrit.cloudera.org:8080/18682 Reviewed-by: Impala Public Jenkins <[email protected]> Tested-by: Impala Public Jenkins <[email protected]> --- fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java | 3 ++- fe/src/main/java/org/apache/impala/util/EventSequence.java | 8 ++++++-- 2 files changed, 8 insertions(+), 3 deletions(-) diff --git a/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java b/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java index 836a2da79..5f62f9bfd 100644 --- a/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java +++ b/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java @@ -416,7 +416,8 @@ public class AnalysisContext { } catch (AnalysisException e) { analysisException = e; } - timeline_.markEvent("Analysis finished"); + long durationMs = timeline_.markEvent("Analysis finished") / 1000000; + LOG.info("Analysis took {} ms", durationMs); // Authorize statement and record exception. Authorization relies on information // collected during analysis. diff --git a/fe/src/main/java/org/apache/impala/util/EventSequence.java b/fe/src/main/java/org/apache/impala/util/EventSequence.java index d137208c1..72b1126d9 100644 --- a/fe/src/main/java/org/apache/impala/util/EventSequence.java +++ b/fe/src/main/java/org/apache/impala/util/EventSequence.java @@ -33,10 +33,12 @@ public class EventSequence { private final long startTime_; private final String name_; + private long lastTime_; public EventSequence(String name) { name_ = name; startTime_ = System.nanoTime(); + lastTime_ = startTime_; } /** @@ -45,8 +47,10 @@ public class EventSequence { */ public long markEvent(String label) { // Timestamps should be in ns resolution - long durationNs = System.nanoTime() - startTime_; - timestamps_.add(durationNs); + long currentTime = System.nanoTime(); + long durationNs = currentTime - lastTime_; + lastTime_ = currentTime; + timestamps_.add(currentTime - startTime_); labels_.add(label); return durationNs; }
