You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@asterixdb.apache.org by AsterixDB Code Review <do...@asterix-gerrit.ics.uci.edu> on 2023/10/09 09:02:36 UTC

Change in asterixdb[master]: MB-58657 : Adding query queue time to stats.

From Ayush Tripathi <Ay...@couchbase.com>:

Ayush Tripathi has uploaded this change for review. ( https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/17853 )


Change subject: MB-58657 : Adding query queue time to stats.
......................................................................

MB-58657 : Adding query queue time to stats.

Change-Id: Iee44281c7a8f06319ac4b3a8423be1a1b47eaa99
---
M asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/MetricsPrinter.java
M asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/IStatementExecutor.java
M asterixdb/asterix-app/src/main/java/org/apache/asterix/app/translator/QueryTranslator.java
M asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryServiceServlet.java
M asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryServiceServlet.java
M asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryResultApiServlet.java
M asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/JobResultCallback.java
M asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/ResponseMetrics.java
M asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ResultMetadata.java
9 files changed, 56 insertions(+), 4 deletions(-)



  git pull ssh://asterix-gerrit.ics.uci.edu:29418/asterixdb refs/changes/53/17853/1

diff --git a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/IStatementExecutor.java b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/IStatementExecutor.java
index b47d45d..e10046e 100644
--- a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/IStatementExecutor.java
+++ b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/IStatementExecutor.java
@@ -133,6 +133,7 @@
         private long count;
         private long size;
         private long processedObjects;
+        private long queueWaitTime;
         private Profile profile;
         private ProfileType profileType;
         private long totalWarningsCount;
@@ -154,6 +155,10 @@
             this.size = size;
         }
 
+        public long getQueueWaitTime() {
+            return queueWaitTime;
+        }
+
         public long getProcessedObjects() {
             return processedObjects;
         }
@@ -172,6 +177,10 @@
             }
         }
 
+        public void setQueueWaitTime(long queueWaitTime) {
+            this.queueWaitTime = queueWaitTime;
+        }
+
         public void setJobProfile(ObjectNode profile) {
             this.profile = new Profile(profile);
         }
diff --git a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ResultMetadata.java b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ResultMetadata.java
index 78f84ff..a943814 100644
--- a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ResultMetadata.java
+++ b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ResultMetadata.java
@@ -32,6 +32,8 @@
     private final SessionConfig.OutputFormat format;
     private long jobDuration;
     private long processedObjects;
+    private long createTime;
+    private long startTime;
     private ObjectNode profile;
     private long diskIoCount;
     private Set<Warning> warnings;
@@ -58,6 +60,22 @@
         this.jobDuration = jobDuration;
     }
 
+    public void setCreateTime(long createTime) {
+        this.createTime = createTime;
+    }
+
+    public void setstartTime(long startTime) {
+        this.startTime = startTime;
+    }
+
+    public long getCreateTime() {
+        return createTime;
+    }
+
+    public long getstartTime() {
+        return startTime;
+    }
+
     public void setWarnings(Set<Warning> warnings) {
         this.warnings = warnings;
     }
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryServiceServlet.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryServiceServlet.java
index 695956c..cb5a3a5 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryServiceServlet.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryServiceServlet.java
@@ -206,6 +206,7 @@
         stats.setProcessedObjects(responseStats.getProcessedObjects());
         stats.updateTotalWarningsCount(responseStats.getTotalWarningsCount());
         stats.setCompileTime(responseStats.getCompileTime());
+        stats.setQueueWaitTime(responseStats.getQueueWaitTime());
     }
 
     private static void updatePropertiesFromCC(IStatementExecutor.StatementProperties statementProperties,
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryResultApiServlet.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryResultApiServlet.java
index d9df051..680feeb 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryResultApiServlet.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryResultApiServlet.java
@@ -102,7 +102,7 @@
                 printer.printResults();
                 ResponseMetrics metrics = ResponseMetrics.of(System.nanoTime() - elapsedStart,
                         metadata.getJobDuration(), stats.getCount(), stats.getSize(), metadata.getProcessedObjects(), 0,
-                        metadata.getTotalWarningsCount(), stats.getCompileTime());
+                        metadata.getTotalWarningsCount(), stats.getCompileTime(), stats.getQueueWaitTime());
                 printer.addFooterPrinter(new MetricsPrinter(metrics, HttpUtil.getPreferredCharset(request)));
                 if (metadata.getJobProfile() != null) {
                     printer.addFooterPrinter(new ProfilePrinter(metadata.getJobProfile()));
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryServiceServlet.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryServiceServlet.java
index e14c185..6678c52 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryServiceServlet.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryServiceServlet.java
@@ -359,7 +359,7 @@
         }
         final ResponseMetrics metrics = ResponseMetrics.of(System.nanoTime() - elapsedStart, executionState.duration(),
                 stats.getCount(), stats.getSize(), stats.getProcessedObjects(), errorCount,
-                stats.getTotalWarningsCount(), stats.getCompileTime());
+                stats.getTotalWarningsCount(), stats.getCompileTime(), stats.getQueueWaitTime());
         responsePrinter.addFooterPrinter(new MetricsPrinter(metrics, resultCharset));
         if (isPrintingProfile(stats)) {
             responsePrinter.addFooterPrinter(new ProfilePrinter(stats.getJobProfile()));
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/JobResultCallback.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/JobResultCallback.java
index 66d81d2..78276e0 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/JobResultCallback.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/JobResultCallback.java
@@ -65,6 +65,11 @@
         }
         final ResultMetadata metadata = (ResultMetadata) resultSetMetaData.getMetadata();
         metadata.setJobDuration(resultJobRecord.getJobDuration());
+        IJobManager jobManager =
+                ((ClusterControllerService) appCtx.getServiceContext().getControllerService()).getJobManager();
+        final JobRun run = jobManager.get(jobId);
+        metadata.setCreateTime(run.getCreateTime());
+        metadata.setstartTime(run.getStartTime());
         aggregateJobStats(jobId, metadata);
     }
 
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/ResponseMetrics.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/ResponseMetrics.java
index d55bb07..08e7702 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/ResponseMetrics.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/ResponseMetrics.java
@@ -29,12 +29,13 @@
     private long warnCount;
     private long diskIoCount;
     private long compileTime;
+    private long queueWaitTime;
 
     private ResponseMetrics() {
     }
 
     public static ResponseMetrics of(long elapsedTime, long executionTime, long resultCount, long resultSize,
-            long processedObjects, long errorCount, long warnCount, long compileTime) {
+            long processedObjects, long errorCount, long warnCount, long compileTime, long queueWaitTime) {
         ResponseMetrics metrics = new ResponseMetrics();
         metrics.elapsedTime = elapsedTime;
         metrics.executionTime = executionTime;
@@ -44,6 +45,7 @@
         metrics.errorCount = errorCount;
         metrics.warnCount = warnCount;
         metrics.compileTime = compileTime;
+        metrics.queueWaitTime = queueWaitTime;
         return metrics;
     }
 
@@ -78,4 +80,8 @@
     public long getCompileTime() {
         return compileTime;
     }
+
+    public long getQueueWaitTime() {
+        return queueWaitTime;
+    }
 }
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/MetricsPrinter.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/MetricsPrinter.java
index 6b1d670..981e216 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/MetricsPrinter.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/MetricsPrinter.java
@@ -37,7 +37,8 @@
         RESULT_SIZE("resultSize"),
         ERROR_COUNT("errorCount"),
         PROCESSED_OBJECTS_COUNT("processedObjects"),
-        WARNING_COUNT("warningCount");
+        WARNING_COUNT("warningCount"),
+        QUEUE_WAIT_TIME("queueWaitTime");
 
         private final String str;
 
@@ -76,6 +77,8 @@
         pw.print("\n\t");
         ResultUtil.printField(pw, Metrics.RESULT_COUNT.str(), metrics.getResultCount(), true);
         pw.print("\n\t");
+        ResultUtil.printField(pw, Metrics.QUEUE_WAIT_TIME.str(),
+                Duration.formatNanos(metrics.getQueueWaitTime(), useAscii));
         ResultUtil.printField(pw, Metrics.RESULT_SIZE.str(), metrics.getResultSize(), true);
         pw.print("\n\t");
         final boolean hasErrors = metrics.getErrorCount() > 0;
diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/translator/QueryTranslator.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/translator/QueryTranslator.java
index 455567d..078409d 100644
--- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/translator/QueryTranslator.java
+++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/translator/QueryTranslator.java
@@ -5105,6 +5105,7 @@
                 (org.apache.asterix.translator.ResultMetadata) controllerService.getResultDirectoryService()
                         .getResultMetadata(jobId, rsId);
         stats.setProcessedObjects(resultMetadata.getProcessedObjects());
+        stats.setQueueWaitTime(resultMetadata.getstartTime() - resultMetadata.getCreateTime());
         if (jobFlags.contains(JobFlag.PROFILE_RUNTIME)) {
             stats.setJobProfile(resultMetadata.getJobProfile());
             apiFramework.generateOptimizedLogicalPlanWithProfile(resultMetadata.getJobProfile());

-- 
To view, visit https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/17853
To unsubscribe, or for help writing mail filters, visit https://asterix-gerrit.ics.uci.edu/settings

Gerrit-Project: asterixdb
Gerrit-Branch: master
Gerrit-Change-Id: Iee44281c7a8f06319ac4b3a8423be1a1b47eaa99
Gerrit-Change-Number: 17853
Gerrit-PatchSet: 1
Gerrit-Owner: Ayush Tripathi <Ay...@couchbase.com>
Gerrit-MessageType: newchange