>From Ali Alsuliman <[email protected]>:
Ali Alsuliman has uploaded this change for review. (
https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/21151?usp=email )
Change subject: [NO ISSUE][OTH] Async metrics
......................................................................
[NO ISSUE][OTH] Async metrics
- user model changes: no
- storage format changes: no
- interface changes: no
Details:
Ext-ref: MB-69805, MB-71461
Change-Id: Ifa04a02b8d950ae6e283c940e679cb2e25acee48
---
M
asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/BaseClientRequest.java
M
asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ClientRequest.java
M
asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/IStatementExecutor.java
M
asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ResultMetadata.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/NCQueryStatusApiServlet.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/api/http/server/QueryServiceServlet.java
M
asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryStatusApiServlet.java
M
asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoRequestMessage.java
M
asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoResponseMessage.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-app/src/main/java/org/apache/asterix/app/result/fields/CreatedAtPrinter.java
M
asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/MetricsPrinter.java
M
asterixdb/asterix-app/src/main/java/org/apache/asterix/app/translator/QueryTranslator.java
M
hyracks-fullstack/hyracks/hyracks-control/hyracks-control-cc/src/main/java/org/apache/hyracks/control/cc/job/JobRun.java
17 files changed, 128 insertions(+), 85 deletions(-)
git pull ssh://asterix-gerrit.ics.uci.edu:29418/asterixdb
refs/changes/51/21151/1
diff --git
a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/BaseClientRequest.java
b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/BaseClientRequest.java
index f49f585..b4ef32e 100644
---
a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/BaseClientRequest.java
+++
b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/BaseClientRequest.java
@@ -129,8 +129,17 @@
private double getElapsedTimeInSecs() {
// this is just an estimation as the request might have been received
on a node with a different system time
+ return getElapsedTimeMillis() / 1000d;
+ }
+
+ public long getElapsedTimeMillis() {
+ // this is just an estimation as the request might have been received
on a node with a different system time
long runningTime = completionTime > 0 ? completionTime :
System.currentTimeMillis();
- return (runningTime - requestReference.getTime()) / 1000d;
+ return (runningTime - requestReference.getTime());
+ }
+
+ public long getRequestTimeMillis() {
+ return requestReference.getTime();
}
protected abstract void doCancel(ICcApplicationContext appCtx) throws
HyracksDataException;
diff --git
a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ClientRequest.java
b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ClientRequest.java
index bd67c50..5c8310d 100644
---
a/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ClientRequest.java
+++
b/asterixdb/asterix-algebra/src/main/java/org/apache/asterix/translator/ClientRequest.java
@@ -50,6 +50,7 @@
protected final JobState jobState;
protected volatile JobId jobId;
private volatile String plan; // can be null
+ private volatile long compileTimeNanos;
public ClientRequest(ICommonRequestParameters requestParameters) {
super(requestParameters.getRequestReference());
@@ -108,6 +109,14 @@
return creationSystemTime;
}
+ public void setCompileTimeNanos(long compileTimeNanos) {
+ this.compileTimeNanos = compileTimeNanos;
+ }
+
+ public long getCompileTimeNanos() {
+ return compileTimeNanos;
+ }
+
@Override
public ObjectNode asJson() {
ObjectNode json = super.asJson();
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 41c1532..90bfc37 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
@@ -185,7 +185,7 @@
this.size = size;
}
- public long getQueueWaitTime() {
+ public long getQueueWaitTimeNanos() {
return queueWaitTime;
}
@@ -207,8 +207,8 @@
}
}
- public void setQueueWaitTime(long queueWaitTime) {
- this.queueWaitTime = queueWaitTime;
+ public void setQueueWaitTimeNanos(long queueWaitTimeNanos) {
+ this.queueWaitTime = queueWaitTimeNanos;
}
public void setJobProfile(ObjectNode profile) {
@@ -227,11 +227,11 @@
this.profileType = profileType;
}
- public void setCompileTime(long compileTime) {
- this.compileTime = compileTime;
+ public void setCompileTimeNanos(long compileTimeNanos) {
+ this.compileTime = compileTimeNanos;
}
- public long getCompileTime() {
+ public long getCompileTimeNanos() {
return compileTime;
}
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 66b2503..2b9a522 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
@@ -155,12 +155,12 @@
return outputTypes;
}
- public long getQueueWaitTimeInNanos() {
+ public long getQueueWaitTimeNanos() {
return queueWaitTimeInNanos;
}
- public void setQueueWaitTimeInNanos(long queueWaitTimeInNanos) {
- this.queueWaitTimeInNanos = queueWaitTimeInNanos;
+ public void setQueueWaitTimeNanos(long queueWaitTimeNanos) {
+ this.queueWaitTimeInNanos = queueWaitTimeNanos;
}
public void setResultCount(long resultCount) {
@@ -171,28 +171,28 @@
return resultCount;
}
- public long getCompileTime() {
+ public long getCompileTimeNanos() {
return compileTime;
}
- public void setCompileTime(long compileTime) {
- this.compileTime = compileTime;
+ public void setCompileTimeNanos(long compileTimeNanos) {
+ this.compileTime = compileTimeNanos;
}
- public long getCreateTime() {
+ public long getCreateTimeMillis() {
return createTime;
}
- public void setCreateTime(long createTime) {
- this.createTime = createTime;
+ public void setCreateTimeMillis(long createTimeMillis) {
+ this.createTime = createTimeMillis;
}
- public long getEndTime() {
+ public long getEndTimeNanos() {
return endTime;
}
- public void setEndTime(long endTime) {
- this.endTime = endTime;
+ public void setEndTimeNanos(long endTimeNanos) {
+ this.endTime = endTimeNanos;
}
public boolean isResultSetOrdered() {
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 818205d..620c75d 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
@@ -215,8 +215,8 @@
stats.setJobProfile(responseStats.getJobProfile());
stats.setProcessedObjects(responseStats.getProcessedObjects());
stats.updateTotalWarningsCount(responseStats.getTotalWarningsCount());
- stats.setCompileTime(responseStats.getCompileTime());
- stats.setQueueWaitTime(responseStats.getQueueWaitTime());
+ stats.setCompileTimeNanos(responseStats.getCompileTimeNanos());
+ stats.setQueueWaitTimeNanos(responseStats.getQueueWaitTimeNanos());
stats.setBufferCacheHitRatio(responseStats.getBufferCacheHitRatio());
stats.setBufferCachePageReadCount(responseStats.getBufferCachePageReadCount());
stats.setCloudReadRequestsCount(responseStats.getCloudReadRequestsCount());
diff --git
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryStatusApiServlet.java
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryStatusApiServlet.java
index 8244f92..cb77fb0 100644
---
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryStatusApiServlet.java
+++
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/NCQueryStatusApiServlet.java
@@ -62,7 +62,8 @@
if (responseMessage == null ||
!responseMessage.isValidRequestId()) {
return;
}
- printMetrics(printer, request, status,
responseMessage.getRequestCreateTime(),
+ printMetricsWithoutMetadata(printer, request, status,
responseMessage.getRequestTime(),
+ responseMessage.getCompileTimeNanos(),
responseMessage.getElapsedTime(),
responseMessage.getJobCreateTime(),
responseMessage.getJobStartTime(),
responseMessage.getJobQueueWaitTime());
} catch (Exception e) {
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 ad3a9de..eb0881d 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
@@ -150,7 +150,7 @@
printer.addFooterPrinter(new
ProfilePrinter(metadata.getJobProfile()));
}
if (handle.getRequestId() != null) {
- printer.addFooterPrinter(new
CreatedAtPrinter(metadata.getCreateTime()));
+ printer.addFooterPrinter(new
CreatedAtPrinter(metadata.getCreateTimeMillis()));
}
printer.printFooters();
printer.end();
@@ -166,18 +166,18 @@
}
private ResponseMetrics buildMetrics(Stats stats, ResultMetadata metadata)
{
- long endTime = System.nanoTime();
+ long endTime = System.currentTimeMillis();
stats.setProcessedObjects(metadata.getProcessedObjects());
- stats.setQueueWaitTime(metadata.getQueueWaitTimeInNanos());
+ stats.setQueueWaitTimeNanos(metadata.getQueueWaitTimeNanos());
stats.setBufferCacheHitRatio(metadata.getBufferCacheHitRatio());
stats.setBufferCachePageReadCount(metadata.getBufferCachePageReadCount());
stats.setCloudReadRequestsCount(metadata.getCloudReadRequestsCount());
stats.setCloudPagesReadCount(metadata.getCloudPagesReadCount());
stats.setCloudPagesPersistedCount(metadata.getCloudPagesPersistedCount());
stats.updateTotalWarningsCount(metadata.getTotalWarningsCount());
- return ResponseMetrics.of(TimeUnit.MILLISECONDS.toNanos(endTime -
metadata.getCreateTime()),
+ return ResponseMetrics.of(TimeUnit.MILLISECONDS.toNanos(endTime -
metadata.getCreateTimeMillis()),
metadata.getJobDuration(), stats.getCount(), stats.getSize(),
metadata.getProcessedObjects(), 0,
- metadata.getTotalWarningsCount(), metadata.getCompileTime(),
stats.getQueueWaitTime(),
+ metadata.getTotalWarningsCount(),
metadata.getCompileTimeNanos(), stats.getQueueWaitTimeNanos(),
stats.getBufferCacheHitRatio(),
stats.getBufferCachePageReadCount(), stats.getCloudReadRequestsCount(),
stats.getCloudPagesReadCount(),
stats.getCloudPagesPersistedCount());
}
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 3be4d84..879332c 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
@@ -315,7 +315,7 @@
ResultDelivery delivery) {
final ResponseMetrics metrics = ResponseMetrics.of(System.nanoTime() -
elapsedStart, executionState.duration(),
stats.getCount(), stats.getSize(),
stats.getProcessedObjects(), errorCount,
- stats.getTotalWarningsCount(), stats.getCompileTime(),
stats.getQueueWaitTime(),
+ stats.getTotalWarningsCount(), stats.getCompileTimeNanos(),
stats.getQueueWaitTimeNanos(),
stats.getBufferCacheHitRatio(),
stats.getBufferCachePageReadCount(), stats.getCloudReadRequestsCount(),
stats.getCloudPagesReadCount(),
stats.getCloudPagesPersistedCount());
if (ResultDelivery.ASYNC != delivery) {
diff --git
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryStatusApiServlet.java
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryStatusApiServlet.java
index cf70ef4..f94a98b 100644
---
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryStatusApiServlet.java
+++
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/api/http/server/QueryStatusApiServlet.java
@@ -185,16 +185,17 @@
public void printMetricsWithResultMetadata(ResponsePrinter printer,
IServletRequest request,
ResultMetadata metadata) {
- long endTime = System.currentTimeMillis();
- ResponseMetrics metrics =
ResponseMetrics.of(TimeUnit.MILLISECONDS.toNanos(endTime -
metadata.getCreateTime()),
+ //TODO: check elapsedTime calculation.
+ ResponseMetrics metrics = ResponseMetrics.of(
+ metadata.getCompileTimeNanos() +
metadata.getQueueWaitTimeNanos() + metadata.getJobDuration(),
metadata.getJobDuration(), 0, 0,
metadata.getProcessedObjects(), 0, metadata.getTotalWarningsCount(),
- metadata.getCompileTime(), metadata.getQueueWaitTimeInNanos(),
0, 0, 0, 0, 0);
+ metadata.getCompileTimeNanos(),
metadata.getQueueWaitTimeNanos(), 0, 0, 0, 0, 0);
printer.addFooterPrinter(new MetricsPrinter(metrics,
HttpUtil.getPreferredCharset(request),
Set.of(MetricsPrinter.Metrics.ELAPSED_TIME,
MetricsPrinter.Metrics.EXECUTION_TIME,
MetricsPrinter.Metrics.QUEUE_WAIT_TIME,
MetricsPrinter.Metrics.COMPILE_TIME,
MetricsPrinter.Metrics.WARNING_COUNT,
MetricsPrinter.Metrics.ERROR_COUNT,
MetricsPrinter.Metrics.PROCESSED_OBJECTS_COUNT)));
- printer.addFooterPrinter(new
CreatedAtPrinter(metadata.getCreateTime()));
+ printer.addFooterPrinter(new
CreatedAtPrinter(metadata.getCreateTimeMillis()));
}
public void printMetricsWithoutResultMetadata(ResponsePrinter printer,
IServletRequest request, String requestId,
@@ -202,31 +203,38 @@
try {
ClusterControllerService ccs = (ClusterControllerService)
appCtx.getServiceContext().getControllerService();
JobRun run = ccs.getJobManager().get(jobId);
- Optional<IClientRequest> clientRequest =
+ Optional<IClientRequest> clientRequestOpt =
((ICcApplicationContext)
appCtx).getRequestTracker().getAsyncOrDeferredRequest(requestId);
- long requestCreateTime = ((ClientRequest)
clientRequest.get()).getCreationSystemTime();
- printMetrics(printer, request, status, requestCreateTime,
run.getCreateTime(), run.getStartTime(),
- run.getQueueWaitTimeInMillis());
+ long requestTimeMillis = 0;
+ long compileTimeNanos = 0;
+ long elapsedTimeMillis = 0;
+ if (clientRequestOpt.isPresent()) {
+ ClientRequest clientRequest = (ClientRequest)
clientRequestOpt.get();
+ requestTimeMillis = clientRequest.getRequestTimeMillis();
+ compileTimeNanos = clientRequest.getCompileTimeNanos();
+ elapsedTimeMillis = clientRequest.getElapsedTimeMillis();
+ }
+ printMetricsWithoutMetadata(printer, request, status,
requestTimeMillis, compileTimeNanos,
+ elapsedTimeMillis, run.getCreateTime(),
run.getStartTime(), run.getQueueWaitTime());
} catch (Exception e) {
throw HyracksDataException.create(e);
}
}
- protected void printMetrics(ResponsePrinter printer, IServletRequest
request, ResultStatus status,
- long requestCreateTime, long jobCreateTime, long jobStartTime,
long queueWaitTime) {
+ protected void printMetricsWithoutMetadata(ResponsePrinter printer,
IServletRequest request, ResultStatus status,
+ long requestTimeMillis, long compileTimeNanos, long
elapsedTimeMillis, long jobCreateTimeMillis,
+ long jobStartTimeMillis, long queueWaitTimeMillis) {
long currentTime = System.currentTimeMillis();
- long elapsedTime = TimeUnit.MILLISECONDS.toNanos(currentTime -
requestCreateTime);
- long compileTime = TimeUnit.MILLISECONDS.toNanos(jobCreateTime -
requestCreateTime);
- long executionTime =
- status == ResultStatus.RUNNING ?
TimeUnit.MILLISECONDS.toNanos(currentTime - jobStartTime) : 0;
+ long elapsedTimeNanos =
TimeUnit.MILLISECONDS.toNanos(elapsedTimeMillis);
+ long executionTimeNanos = status == ResultStatus.RUNNING ?
elapsedTimeNanos : 0;
- ResponseMetrics metrics = ResponseMetrics.of(elapsedTime,
executionTime, 0, 0, 0, 0, 0, compileTime,
- queueWaitTime, 0, 0, 0, 0, 0);
+ ResponseMetrics metrics = ResponseMetrics.of(elapsedTimeNanos,
executionTimeNanos, 0, 0, 0, 0, 0,
+ compileTimeNanos,
TimeUnit.MILLISECONDS.toNanos(queueWaitTimeMillis), 0, 0, 0, 0, 0);
printer.addFooterPrinter(new MetricsPrinter(metrics,
HttpUtil.getPreferredCharset(request),
Set.of(MetricsPrinter.Metrics.ELAPSED_TIME,
MetricsPrinter.Metrics.EXECUTION_TIME,
MetricsPrinter.Metrics.QUEUE_WAIT_TIME,
MetricsPrinter.Metrics.COMPILE_TIME)));
- printer.addFooterPrinter(new CreatedAtPrinter(requestCreateTime));
+ printer.addFooterPrinter(new CreatedAtPrinter(requestTimeMillis));
}
}
diff --git
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoRequestMessage.java
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoRequestMessage.java
index 0e71719..2e53762 100644
---
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoRequestMessage.java
+++
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoRequestMessage.java
@@ -54,18 +54,19 @@
@Override
public void handle(ICcApplicationContext appCtx) throws
HyracksDataException {
CCMessageBroker messageBroker = (CCMessageBroker)
appCtx.getServiceContext().getMessageBroker();
- Optional<IClientRequest> clientRequest =
appCtx.getRequestTracker().getAsyncOrDeferredRequest(requestId);
+ Optional<IClientRequest> clientRequestOpt =
appCtx.getRequestTracker().getAsyncOrDeferredRequest(requestId);
ClientInfoResponseMessage response;
- if (clientRequest.isEmpty() || !jobId.equals(((ClientRequest)
clientRequest.get()).getJobId())) {
+ if (clientRequestOpt.isEmpty() || !jobId.equals(((ClientRequest)
clientRequestOpt.get()).getJobId())) {
response = new ClientInfoResponseMessage(ncReqId, false);
} else {
if (metricsRequired) {
ClusterControllerService ccs =
(ClusterControllerService)
appCtx.getServiceContext().getControllerService();
JobRun run = ccs.getJobManager().get(jobId);
- response = new ClientInfoResponseMessage(ncReqId, true,
- ((ClientRequest)
clientRequest.get()).getCreationSystemTime(), run.getCreateTime(),
- run.getStartTime(), run.getEndTime(),
run.getQueueWaitTimeInMillis());
+ ClientRequest clientRequest = (ClientRequest)
clientRequestOpt.get();
+ response = new ClientInfoResponseMessage(ncReqId, true,
clientRequest.getRequestTimeMillis(),
+ clientRequest.getCompileTimeNanos(),
clientRequest.getElapsedTimeMillis(), run.getCreateTime(),
+ run.getStartTime(), run.getEndTime(),
run.getQueueWaitTime());
} else {
response = new ClientInfoResponseMessage(ncReqId, true);
}
diff --git
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoResponseMessage.java
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoResponseMessage.java
index 29200c5..830c3d8 100644
---
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoResponseMessage.java
+++
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/message/ClientInfoResponseMessage.java
@@ -30,21 +30,26 @@
private final long reqId;
private final boolean validRequestId;
// All time are in millis
- private final long requestCreateTime;
+ private final long requestTime;
private final long jobCreateTime;
+ private final long elapsedTime;
private final long jobStartTime;
private final long jobEndTime;
private final long jobQueueWaitTime;
+ private final long compileTimeNanos;
+
public ClientInfoResponseMessage(long reqId, boolean validRequestId) {
- this(reqId, validRequestId, 0, 0, 0, 0, 0);
+ this(reqId, validRequestId, 0, 0, 0, 0, 0, 0, 0);
}
- public ClientInfoResponseMessage(long reqId, boolean validRequestId, long
requestCreateTime, long jobCreateTime,
- long jobStartTime, long jobEndTime, long jobQueueWaitTime) {
+ public ClientInfoResponseMessage(long reqId, boolean validRequestId, long
requestTime, long compileTimeNanos,
+ long elapsedTime, long jobCreateTime, long jobStartTime, long
jobEndTime, long jobQueueWaitTime) {
this.reqId = reqId;
this.validRequestId = validRequestId;
- this.requestCreateTime = requestCreateTime;
+ this.requestTime = requestTime;
+ this.compileTimeNanos = compileTimeNanos;
+ this.elapsedTime = elapsedTime;
this.jobStartTime = jobStartTime;
this.jobCreateTime = jobCreateTime;
this.jobEndTime = jobEndTime;
@@ -64,8 +69,16 @@
return validRequestId;
}
- public long getRequestCreateTime() {
- return requestCreateTime;
+ public long getRequestTime() {
+ return requestTime;
+ }
+
+ public long getCompileTimeNanos() {
+ return compileTimeNanos;
+ }
+
+ public long getElapsedTime() {
+ return elapsedTime;
}
public long getJobCreateTime() {
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 ef36bc8..0080a17 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
@@ -107,8 +107,8 @@
}
}
}
- metadata.setEndTime(System.currentTimeMillis());
-
metadata.setQueueWaitTimeInNanos(TimeUnit.MILLISECONDS.toNanos(run.getQueueWaitTimeInMillis()));
+ metadata.setEndTimeNanos(System.nanoTime());
+
metadata.setQueueWaitTimeNanos(TimeUnit.MILLISECONDS.toNanos(run.getQueueWaitTime()));
}
metadata.setProcessedObjects(processedObjects);
metadata.setBufferCacheHitRatio(pagesRead > 0 ? (pagesRead -
nonPagedReads) / (double) pagesRead : Double.NaN);
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 766618f..6ef195a 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
@@ -39,20 +39,20 @@
private ResponseMetrics() {
}
- public static ResponseMetrics of(long elapsedTime, long executionTime,
long resultCount, long resultSize,
- long processedObjects, long errorCount, long warnCount, long
compileTime, long queueWaitTime,
+ public static ResponseMetrics of(long elapsedTimeNanos, long
executionTimeNanos, long resultCount, long resultSize,
+ long processedObjects, long errorCount, long warnCount, long
compileTimeNanos, long queueWaitTimeNanos,
double bufferCacheHitRatio, long bufferCachePageReadCount, long
cloudRequestsCount,
long cloudPagesReadCount, long cloudPagesPersistedCount) {
ResponseMetrics metrics = new ResponseMetrics();
- metrics.elapsedTime = elapsedTime;
- metrics.executionTime = executionTime;
+ metrics.elapsedTime = elapsedTimeNanos;
+ metrics.executionTime = executionTimeNanos;
metrics.resultCount = resultCount;
metrics.resultSize = resultSize;
metrics.processedObjects = processedObjects;
metrics.errorCount = errorCount;
metrics.warnCount = warnCount;
- metrics.compileTime = compileTime;
- metrics.queueWaitTime = queueWaitTime;
+ metrics.compileTime = compileTimeNanos;
+ metrics.queueWaitTime = queueWaitTimeNanos;
metrics.bufferCacheHitRatio = bufferCacheHitRatio;
metrics.bufferCachePageReadCount = bufferCachePageReadCount;
metrics.cloudReadRequestsCount = cloudRequestsCount;
@@ -61,11 +61,11 @@
return metrics;
}
- public long getElapsedTime() {
+ public long getElapsedTimeNanos() {
return elapsedTime;
}
- public long getExecutionTime() {
+ public long getExecutionTimeNanos() {
return executionTime;
}
@@ -89,11 +89,11 @@
return warnCount;
}
- public long getCompileTime() {
+ public long getCompileTimeNanos() {
return compileTime;
}
- public long getQueueWaitTime() {
+ public long getQueueWaitTimeNanos() {
return queueWaitTime;
}
diff --git
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/CreatedAtPrinter.java
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/CreatedAtPrinter.java
index d7192f5..4b9093f 100644
---
a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/CreatedAtPrinter.java
+++
b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/result/fields/CreatedAtPrinter.java
@@ -27,16 +27,16 @@
public class CreatedAtPrinter implements IResponseFieldPrinter {
public static final String FIELD_NAME = "createdAt";
- private final long createdAt;
+ private final long createdAtMillis;
- public CreatedAtPrinter(long createdAt) {
- this.createdAt = createdAt;
+ public CreatedAtPrinter(long createdAtMillis) {
+ this.createdAtMillis = createdAtMillis;
}
@Override
public void print(PrintWriter pw) {
pw.append("\t\"").append(FIELD_NAME).append("\": \"")
-
.append(DateTimeFormatter.ISO_INSTANT.format(Instant.ofEpochMilli(createdAt))).append("\"");
+
.append(DateTimeFormatter.ISO_INSTANT.format(Instant.ofEpochMilli(createdAtMillis))).append("\"");
}
@Override
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 368c0da..c05afdc 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
@@ -125,17 +125,17 @@
List<Entry> entries = new ArrayList<>();
if (isSelected(Metrics.ELAPSED_TIME))
- entries.add(
- new StringEntry(Metrics.ELAPSED_TIME,
Duration.formatNanos(metrics.getElapsedTime(), useAscii)));
+ entries.add(new StringEntry(Metrics.ELAPSED_TIME,
+ Duration.formatNanos(metrics.getElapsedTimeNanos(),
useAscii)));
if (isSelected(Metrics.EXECUTION_TIME))
entries.add(new StringEntry(Metrics.EXECUTION_TIME,
- Duration.formatNanos(metrics.getExecutionTime(),
useAscii)));
+ Duration.formatNanos(metrics.getExecutionTimeNanos(),
useAscii)));
if (isSelected(Metrics.COMPILE_TIME))
- entries.add(
- new StringEntry(Metrics.COMPILE_TIME,
Duration.formatNanos(metrics.getCompileTime(), useAscii)));
+ entries.add(new StringEntry(Metrics.COMPILE_TIME,
+ Duration.formatNanos(metrics.getCompileTimeNanos(),
useAscii)));
if (isSelected(Metrics.QUEUE_WAIT_TIME))
entries.add(new StringEntry(Metrics.QUEUE_WAIT_TIME,
- Duration.formatNanos(metrics.getQueueWaitTime(),
useAscii)));
+ Duration.formatNanos(metrics.getQueueWaitTimeNanos(),
useAscii)));
if (isSelected(Metrics.RESULT_COUNT))
entries.add(new LongEntry(Metrics.RESULT_COUNT,
metrics.getResultCount()));
if (isSelected(Metrics.RESULT_SIZE))
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 64c0254..1b1364b 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
@@ -4376,7 +4376,8 @@
stats.updateTotalWarningsCount(warningCollector.getTotalWarningsCount());
afterCompile();
MetadataManager.INSTANCE.commitTransaction(mdTxnCtx);
- stats.setCompileTime(System.nanoTime() - compileStart);
+ stats.setCompileTimeNanos(System.nanoTime() - compileStart);
+ clientRequest.setCompileTimeNanos(stats.getCompileTimeNanos());
bActiveTxn = false;
return isCompileOnly() ? null : jobSpec;
} catch (Exception e) {
@@ -5570,15 +5571,16 @@
try {
org.apache.asterix.translator.ResultMetadata resultMetadata =
new
org.apache.asterix.translator.ResultMetadata(sessionConfig.fmt());
- resultMetadata.setCreateTime(System.currentTimeMillis());
+
resultMetadata.setCreateTimeMillis(clientRequest.getRequestTimeMillis());
final JobSpecification jobSpec = rewriteCompileQuery(hcc,
metadataProvider, query, null, stmtParams,
requestParameters, resultMetadata);
// update stats with count of compile-time warnings. needs to
be adapted for multi-statement.
stats.updateTotalWarningsCount(warningCollector.getTotalWarningsCount());
afterCompile();
MetadataManager.INSTANCE.commitTransaction(mdTxnCtx);
- stats.setCompileTime(System.nanoTime() - compileStart);
- resultMetadata.setCompileTime(stats.getCompileTime());
+ stats.setCompileTimeNanos(System.nanoTime() - compileStart);
+ clientRequest.setCompileTimeNanos(stats.getCompileTimeNanos());
+
resultMetadata.setCompileTimeNanos(stats.getCompileTimeNanos());
bActiveTxn = false;
return query.isExplain() || query.isAdvise() ||
isCompileOnly() ? null : jobSpec;
} catch (Exception e) {
@@ -5673,7 +5675,7 @@
(org.apache.asterix.translator.ResultMetadata)
controllerService.getResultDirectoryService()
.getResultMetadata(jobId, rsId);
stats.setProcessedObjects(resultMetadata.getProcessedObjects());
- stats.setQueueWaitTime(resultMetadata.getQueueWaitTimeInNanos());
+ stats.setQueueWaitTimeNanos(resultMetadata.getQueueWaitTimeNanos());
stats.setBufferCacheHitRatio(resultMetadata.getBufferCacheHitRatio());
stats.setBufferCachePageReadCount(resultMetadata.getBufferCachePageReadCount());
stats.setCloudReadRequestsCount(resultMetadata.getCloudReadRequestsCount());
diff --git
a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-cc/src/main/java/org/apache/hyracks/control/cc/job/JobRun.java
b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-cc/src/main/java/org/apache/hyracks/control/cc/job/JobRun.java
index da4d12d..6b09961 100644
---
a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-cc/src/main/java/org/apache/hyracks/control/cc/job/JobRun.java
+++
b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-cc/src/main/java/org/apache/hyracks/control/cc/job/JobRun.java
@@ -222,7 +222,7 @@
this.profile.setEndTime(endTime);
}
- public long getQueueWaitTimeInMillis() {
+ public long getQueueWaitTime() {
return startTime > 0 ? startTime - createTime :
System.currentTimeMillis() - createTime;
}
--
To view, visit https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/21151?usp=email
To unsubscribe, or for help writing mail filters, visit
https://asterix-gerrit.ics.uci.edu/settings?usp=email
Gerrit-MessageType: newchange
Gerrit-Project: asterixdb
Gerrit-Branch: lumina
Gerrit-Change-Id: Ifa04a02b8d950ae6e283c940e679cb2e25acee48
Gerrit-Change-Number: 21151
Gerrit-PatchSet: 1
Gerrit-Owner: Ali Alsuliman <[email protected]>
