This is an automated email from the ASF dual-hosted git repository.
alsuliman pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/asterixdb.git
The following commit(s) were added to refs/heads/master by this push:
new 18d4d80a16 [ASTERIXDB-3277][API] Adding query queue time to stats data.
new dfd49d580e Merge branch 'gerrit/trinity' into 'master'
18d4d80a16 is described below
commit 18d4d80a167eee8072033a47b4cbfe36ea13bdf5
Author: Ayush Tripathi <[email protected]>
AuthorDate: Mon Oct 9 12:03:57 2023 +0530
[ASTERIXDB-3277][API] Adding query queue time to stats data.
- user model changes: yes
- storage format changes: no
- interface changes: no
Details:
Adding query waiting time inside job queue as a part of returned metric.
-added queueWaitTime inside stats.
-adding queueWaitTime inside metric and reading it from stats.
Change-Id: I1ff41693e7080abe5535c402d0dbb6b8bc387a37
Reviewed-on: https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/17854
Integration-Tests: Jenkins <[email protected]>
Tested-by: Jenkins <[email protected]>
Reviewed-by: Peeyush Gupta <[email protected]>
---
.../java/org/apache/asterix/translator/IStatementExecutor.java | 9 +++++++++
.../apache/asterix/api/http/server/NCQueryServiceServlet.java | 1 +
.../apache/asterix/api/http/server/QueryResultApiServlet.java | 2 +-
.../org/apache/asterix/api/http/server/QueryServiceServlet.java | 2 +-
.../main/java/org/apache/asterix/app/result/ResponseMetrics.java | 8 +++++++-
.../org/apache/asterix/app/result/fields/MetricsPrinter.java | 4 ++++
.../java/org/apache/asterix/app/translator/QueryTranslator.java | 4 ++++
.../request-param-validation-400-BAD.01.regexjson | 1 +
.../results/warnings/warnings-limit/warnings-limit.03.regexadm | 1 +
.../results/warnings/warnings-limit/warnings-limit.04.regexadm | 1 +
.../results/warnings/warnings-limit/warnings-limit.05.regexadm | 1 +
.../results/warnings/warnings-limit/warnings-limit.06.regexadm | 1 +
.../results/warnings/warnings-limit/warnings-limit.07.regexadm | 1 +
.../results/warnings/warnings-limit/warnings-limit.08.regexadm | 1 +
.../hyracks/control/common/job/profiling/om/JobProfile.java | 5 +++++
15 files changed, 39 insertions(+), 3 deletions(-)
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 b47d45d027..e10046e55f 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 @@ public interface IStatementExecutor {
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 @@ public interface IStatementExecutor {
this.size = size;
}
+ public long getQueueWaitTime() {
+ return queueWaitTime;
+ }
+
public long getProcessedObjects() {
return processedObjects;
}
@@ -172,6 +177,10 @@ public interface IStatementExecutor {
}
}
+ public void setQueueWaitTime(long queueWaitTime) {
+ this.queueWaitTime = queueWaitTime;
+ }
+
public void setJobProfile(ObjectNode profile) {
this.profile = new Profile(profile);
}
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 695956c6ff..cb5a3a5fae 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 @@ public class NCQueryServiceServlet extends
QueryServiceServlet {
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 d9df051ff4..680feeb178 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 @@ public class QueryResultApiServlet extends
AbstractQueryApiServlet {
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 e14c185d38..6678c52851 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 @@ public class QueryServiceServlet extends
AbstractQueryApiServlet {
}
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/ResponseMetrics.java
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/ResponseMetrics.java
index d55bb07650..08e7702429 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 @@ public class ResponseMetrics {
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 @@ public class ResponseMetrics {
metrics.errorCount = errorCount;
metrics.warnCount = warnCount;
metrics.compileTime = compileTime;
+ metrics.queueWaitTime = queueWaitTime;
return metrics;
}
@@ -78,4 +80,8 @@ public class ResponseMetrics {
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 6b1d670b22..e001d296ba 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
@@ -33,6 +33,7 @@ public class MetricsPrinter implements IResponseFieldPrinter {
ELAPSED_TIME("elapsedTime"),
EXECUTION_TIME("executionTime"),
COMPILE_TIME("compileTime"),
+ QUEUE_WAIT_TIME("queueWaitTime"),
RESULT_COUNT("resultCount"),
RESULT_SIZE("resultSize"),
ERROR_COUNT("errorCount"),
@@ -74,6 +75,9 @@ public class MetricsPrinter implements IResponseFieldPrinter {
pw.print("\n\t");
ResultUtil.printField(pw, Metrics.COMPILE_TIME.str(),
Duration.formatNanos(metrics.getCompileTime(), useAscii));
pw.print("\n\t");
+ ResultUtil.printField(pw, Metrics.QUEUE_WAIT_TIME.str(),
+ Duration.formatNanos(metrics.getQueueWaitTime(), useAscii));
+ pw.print("\n\t");
ResultUtil.printField(pw, Metrics.RESULT_COUNT.str(),
metrics.getResultCount(), true);
pw.print("\n\t");
ResultUtil.printField(pw, Metrics.RESULT_SIZE.str(),
metrics.getResultSize(), true);
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 cb64c017d8..fc539ef3a0 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
@@ -4778,6 +4778,10 @@ public class QueryTranslator extends
AbstractLangTranslator implements IStatemen
(org.apache.asterix.translator.ResultMetadata)
controllerService.getResultDirectoryService()
.getResultMetadata(jobId, rsId);
stats.setProcessedObjects(resultMetadata.getProcessedObjects());
+ if (controllerService.getJobManager().get(jobId) != null) {
+ stats.setQueueWaitTime(
+
controllerService.getJobManager().get(jobId).getJobProfile().getQueueWaitTimeInNanos());
+ }
if (jobFlags.contains(JobFlag.PROFILE_RUNTIME)) {
stats.setJobProfile(resultMetadata.getJobProfile());
apiFramework.generateOptimizedLogicalPlanWithProfile(resultMetadata.getJobProfile());
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/api/request-param-validation-400-BAD/request-param-validation-400-BAD.01.regexjson
b/asterixdb/asterix-app/src/test/resources/runtimets/results/api/request-param-validation-400-BAD/request-param-validation-400-BAD.01.regexjson
index 6fa99e2c2c..bd58b527ca 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/api/request-param-validation-400-BAD/request-param-validation-400-BAD.01.regexjson
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/api/request-param-validation-400-BAD/request-param-validation-400-BAD.01.regexjson
@@ -7,6 +7,7 @@
"elapsedTime": "R{.*}",
"executionTime": "R{.*}",
"compileTime": "R{.*}",
+ "queueWaitTime": "R{.*}",
"resultCount": 0,
"resultSize": 0,
"processedObjects": 0,
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.03.regexadm
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.03.regexadm
index 7029ce25b8..bd85d0e46d 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.03.regexadm
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.03.regexadm
@@ -32,6 +32,7 @@
\s*\Q"elapsedTime": "\E[^"]+\Q",\E
\s*\Q"executionTime": "\E[^"]+\Q",\E
\s*\Q"compileTime": "\E[^"]+\Q",\E
+\s*\Q"queueWaitTime": "\E[^"]+\Q",\E
\s*\Q"resultCount": \E[0-9]+\Q,\E
\s*\Q"resultSize": \E[0-9]+\Q,\E
\s*\Q"processedObjects": \E[0-9]+\Q,\E
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.04.regexadm
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.04.regexadm
index 8478d17bcd..dce84fe75a 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.04.regexadm
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.04.regexadm
@@ -25,6 +25,7 @@
\s*\Q"elapsedTime": "\E[^"]+\Q",\E
\s*\Q"executionTime": "\E[^"]+\Q",\E
\s*\Q"compileTime": "\E[^"]+\Q",\E
+\s*\Q"queueWaitTime": "\E[^"]+\Q",\E
\s*\Q"resultCount": \E[0-9]+\Q,\E
\s*\Q"resultSize": \E[0-9]+\Q,\E
\s*\Q"processedObjects": \E[0-9]+\Q,\E
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.05.regexadm
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.05.regexadm
index 5399ed8c83..6b1931a742 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.05.regexadm
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.05.regexadm
@@ -25,6 +25,7 @@
\s*\Q"elapsedTime": "\E[^"]+\Q",\E
\s*\Q"executionTime": "\E[^"]+\Q",\E
\s*\Q"compileTime": "\E[^"]+\Q",\E
+\s*\Q"queueWaitTime": "\E[^"]+\Q",\E
\s*\Q"resultCount": \E[0-9]+\Q,\E
\s*\Q"resultSize": \E[0-9]+\Q,\E
\s*\Q"processedObjects": \E[0-9]+\Q,\E
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.06.regexadm
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.06.regexadm
index aa58fb456c..7b689f64bd 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.06.regexadm
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.06.regexadm
@@ -13,6 +13,7 @@
\s*\Q"elapsedTime": "\E[^"]+\Q",\E
\s*\Q"executionTime": "\E[^"]+\Q",\E
\s*\Q"compileTime": "\E[^"]+\Q",\E
+\s*\Q"queueWaitTime": "\E[^"]+\Q",\E
\s*\Q"resultCount": \E[0-9]+\Q,\E
\s*\Q"resultSize": \E[0-9]+\Q,\E
\s*\Q"processedObjects": \E[0-9]+\Q,\E
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.07.regexadm
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.07.regexadm
index 5399ed8c83..6b1931a742 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.07.regexadm
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.07.regexadm
@@ -25,6 +25,7 @@
\s*\Q"elapsedTime": "\E[^"]+\Q",\E
\s*\Q"executionTime": "\E[^"]+\Q",\E
\s*\Q"compileTime": "\E[^"]+\Q",\E
+\s*\Q"queueWaitTime": "\E[^"]+\Q",\E
\s*\Q"resultCount": \E[0-9]+\Q,\E
\s*\Q"resultSize": \E[0-9]+\Q,\E
\s*\Q"processedObjects": \E[0-9]+\Q,\E
diff --git
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.08.regexadm
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.08.regexadm
index 7029ce25b8..bd85d0e46d 100644
---
a/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.08.regexadm
+++
b/asterixdb/asterix-app/src/test/resources/runtimets/results/warnings/warnings-limit/warnings-limit.08.regexadm
@@ -32,6 +32,7 @@
\s*\Q"elapsedTime": "\E[^"]+\Q",\E
\s*\Q"executionTime": "\E[^"]+\Q",\E
\s*\Q"compileTime": "\E[^"]+\Q",\E
+\s*\Q"queueWaitTime": "\E[^"]+\Q",\E
\s*\Q"resultCount": \E[0-9]+\Q,\E
\s*\Q"resultSize": \E[0-9]+\Q,\E
\s*\Q"processedObjects": \E[0-9]+\Q,\E
diff --git
a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-common/src/main/java/org/apache/hyracks/control/common/job/profiling/om/JobProfile.java
b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-common/src/main/java/org/apache/hyracks/control/common/job/profiling/om/JobProfile.java
index f4cd4d6222..871d2bc77b 100644
---
a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-common/src/main/java/org/apache/hyracks/control/common/job/profiling/om/JobProfile.java
+++
b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-common/src/main/java/org/apache/hyracks/control/common/job/profiling/om/JobProfile.java
@@ -26,6 +26,7 @@ import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;
+import java.util.concurrent.TimeUnit;
import org.apache.hyracks.api.dataflow.TaskAttemptId;
import org.apache.hyracks.api.dataflow.TaskId;
@@ -89,6 +90,10 @@ public class JobProfile extends AbstractProfile {
this.endTime = endTime;
}
+ public long getQueueWaitTimeInNanos() {
+ return TimeUnit.MILLISECONDS.toNanos(startTime - createTime);
+ }
+
@Override
public ObjectNode toJSON() {
ObjectMapper om = new ObjectMapper();
