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 2021/12/22 14:38:25 UTC
Change in asterixdb[master]: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
From Michael Blow <mb...@apache.org>:
Michael Blow has uploaded this change for review. ( https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643 )
Change subject: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
......................................................................
[NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
Change-Id: I040523a73e65a0fd86fff3fff38d2278d83ef65f
---
M asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
M asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
M hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
M hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
M hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
11 files changed, 125 insertions(+), 26 deletions(-)
git pull ssh://asterix-gerrit.ics.uci.edu:29418/asterixdb refs/changes/43/14643/1
diff --git a/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java b/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
index 37e589a..7bc3b4f 100644
--- a/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
+++ b/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
@@ -162,7 +162,7 @@
@Override
public void nextFrame(ByteBuffer buffer) throws HyracksDataException {
- long tid = tracer.durationB("Ingestion-Store", traceCategory, null);
+ long tid = tracer.durationB("Ingestion-Store", traceCategory);
try {
if (hasMessage) {
FeedUtils.processFeedMessage(buffer, message, fta);
@@ -172,7 +172,7 @@
LOGGER.log(Level.WARN, "Failure Processing a frame at store side", e);
throw HyracksDataException.create(e);
} finally {
- tracer.durationE(tid, traceCategory, null);
+ tracer.durationE(traceCategory, tid);
}
}
diff --git a/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java b/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
index 591ff9a..1e7f4b7 100644
--- a/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
+++ b/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
@@ -459,7 +459,7 @@
if (tracer.isEnabled(traceCategory) && lastRecordInTimeStamp > 0 && indexHelper != null
&& indexHelper.getIndexInstance() != null) {
tracer.instant("UpsertClose", traceCategory, Scope.t,
- "{\"last-record-in\":\"" + DATE_FORMAT.get().format(new Date(lastRecordInTimeStamp))
+ () -> "{\"last-record-in\":\"" + DATE_FORMAT.get().format(new Date(lastRecordInTimeStamp))
+ "\", \"index\":" + indexHelper.getIndexInstance().toString() + "}");
}
} catch (Throwable traceFailure) {
diff --git a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
index c774317..8c9cbfb 100644
--- a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
+++ b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
@@ -710,7 +710,7 @@
@Override
public void run() {
try {
- tracer.instant("CurrentTime", traceCategory, Tracer.Scope.p, Tracer.dateTimeStamp());
+ tracer.instant("CurrentTime", traceCategory, ITracer.Scope.p, Tracer::dateTimeStamp);
} catch (Exception e) {
LOGGER.log(Level.WARN, "Exception tracing current time", e);
}
diff --git a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
index 59ab2f4..e1acaee 100644
--- a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
+++ b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
@@ -116,7 +116,7 @@
try {
flush(writer);
} finally {
- tracer.durationE(tid, traceCategory, args);
+ tracer.durationE(traceCategory, tid, args);
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
index ec45437..39e223b 100644
--- a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
+++ b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
@@ -157,7 +157,7 @@
flushedBytes = frameTupleAppender.getBuffer().capacity();
long tid = tracer.durationB(name, cat, args);
frameTupleAppender.write(writer, true);
- tracer.durationE(tid, cat, args);
+ tracer.durationE(cat, tid, args);
if (!frameTupleAppender.append(tupleAccessor, tIndex)) {
throw HyracksDataException.create(ErrorCode.TUPLE_CANNOT_FIT_INTO_EMPTY_FRAME,
tupleAccessor.getTupleLength(tIndex));
diff --git a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
index dfb1a17..0813a00 100644
--- a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
+++ b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
@@ -171,7 +171,7 @@
public void logPerformanceCounters(int tupleCount) {
if (isTracingEnabled()) {
tracer.instant("store-counters", traceCategory, Scope.t,
- "{\"count\":" + tupleCount + ",\"enter-exit-duration-ns\":" + enterExitTime + "}");
+ () -> "{\"count\":" + tupleCount + ",\"enter-exit-duration-ns\":" + enterExitTime + "}");
resetCounters();
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
index 92fa135..950a8e5 100644
--- a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
+++ b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
@@ -262,7 +262,7 @@
}
if (inactiveMemoryComponentsToBeCleanedUp != null) {
for (ILSMMemoryComponent c : inactiveMemoryComponentsToBeCleanedUp) {
- tracer.instant(c.toString(), traceCategory, Scope.p, lsmIndex.toString());
+ tracer.instant(c.toString(), traceCategory, Scope.p, lsmIndex::toString);
c.cleanup();
synchronized (opTracker) {
c.reset();
diff --git a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
index 4ab57c5..eb48f82 100644
--- a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
+++ b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
@@ -58,7 +58,7 @@
final long traceCategory = tracer.getRegistry().get(TraceUtils.INDEX_IO_OPERATIONS);
if (tracer.isEnabled(traceCategory)) {
tracer.instant("schedule-" + ioOpName, traceCategory, Scope.p,
- "{\"path\": \"" + ioOp.getTarget().getRelativePath() + "\"}");
+ () -> "{\"path\": \"" + ioOp.getTarget().getRelativePath() + "\"}");
return new TracedIOOperation(ioOp, tracer, traceCategory);
}
return ioOp;
@@ -91,11 +91,11 @@
@Override
public LSMIOOperationStatus call() throws HyracksDataException {
final String name = getTarget().getRelativePath();
- final long tid = tracer.durationB(name, traceCategory, null);
+ final long tid = tracer.durationB(name, traceCategory);
try {
return ioOp.call();
} finally {
- tracer.durationE(ioOp.getIOOpertionType().name().toLowerCase(), traceCategory, tid, "{\"size\":"
+ tracer.durationE(ioOp.getIOOpertionType().name().toLowerCase(), traceCategory, tid, () -> "{\"size\":"
+ getTarget().getFile().length() + ", \"path\": \"" + ioOp.getTarget().getRelativePath() + "\"}");
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
index 9adac04..9b316ba 100644
--- a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
+++ b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
@@ -45,6 +45,10 @@
@Override
protected void afterExecute(Runnable r, Throwable t) {
super.afterExecute(r, t);
- Thread.currentThread().setName(savedName.get());
+ try {
+ Thread.currentThread().setName(savedName.get());
+ } finally {
+ savedName.remove();
+ }
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
index 908dc1c..6a9aa89 100644
--- a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
+++ b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
@@ -19,6 +19,8 @@
package org.apache.hyracks.util.trace;
+import java.util.function.Supplier;
+
public interface ITracer {
enum Phase {
@@ -83,7 +85,7 @@
}
@Override
- public void durationE(long tid, long cat, String args) {
+ public void durationE(long cat, long tid, String args) {
// nothing to do here
}
@@ -91,6 +93,36 @@
public void instant(String name, long cat, Scope scope, String args) {
// nothing to do here
}
+
+ @Override
+ public long durationB(String name, long cat) {
+ return -1;
+ }
+
+ @Override
+ public long durationB(String name, long cat, Supplier<String> args) {
+ return -1;
+ }
+
+ @Override
+ public void durationE(long cat, long tid) {
+ // nothing to do here
+ }
+
+ @Override
+ public void durationE(long cat, long tid, Supplier<String> args) {
+ // nothing to do here
+ }
+
+ @Override
+ public void durationE(String name, long cat, long tid, Supplier<String> args) {
+ // nothing to do here
+ }
+
+ @Override
+ public void instant(String name, long cat, Scope scope, Supplier<String> args) {
+ // nothing to do here
+ }
};
String getName();
@@ -101,14 +133,26 @@
boolean isEnabled(long cat);
+ long durationB(String name, long cat);
+
long durationB(String name, long cat, String args);
- void durationE(long tid, long cat, String args);
+ long durationB(String name, long cat, Supplier<String> args);
+
+ void durationE(long cat, long tid);
+
+ void durationE(long cat, long tid, String args);
+
+ void durationE(long cat, long tid, Supplier<String> args);
void durationE(String name, long cat, long tid, String args);
+ void durationE(String name, long cat, long tid, Supplier<String> args);
+
void instant(String name, long cat, Scope scope, String args);
+ void instant(String name, long cat, Scope scope, Supplier<String> args);
+
@Override
String toString();
}
diff --git a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
index c1c38cf..1359e60 100644
--- a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
+++ b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
@@ -23,6 +23,7 @@
import java.text.SimpleDateFormat;
import java.util.Arrays;
import java.util.Date;
+import java.util.function.Supplier;
import org.apache.hyracks.util.PidHelper;
import org.apache.logging.log4j.Level;
@@ -44,7 +45,7 @@
private long categories;
private final TraceCategoryRegistry registry;
- private static final long pid = PidHelper.getPid();
+ private static final long PID = PidHelper.getPid();
public Tracer(String name, long categories, TraceCategoryRegistry registry) {
final String traceLoggerName = Tracer.class.getName() + ".Traces." + name;
@@ -53,7 +54,7 @@
this.categories = categories;
this.registry = registry;
final long traceCategory = getRegistry().get(TraceUtils.TRACER);
- instant("Trace-Start", traceCategory, Scope.p, dateTimeStamp());
+ instant("Trace-Start", traceCategory, Scope.p, Tracer::dateTimeStamp);
}
public Tracer(String name, String[] categories, TraceCategoryRegistry registry) {
@@ -100,11 +101,25 @@
}
@Override
+ public long durationB(String name, long cat) {
+ if (isEnabled(cat)) {
+ return emitDurationB(name, cat, null);
+ }
+ return -1;
+ }
+
+ @Override
public long durationB(String name, long cat, String args) {
if (isEnabled(cat)) {
- Event e = Event.create(name, cat, Phase.B, pid, Thread.currentThread().getId(), null, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
- return e.tid;
+ return emitDurationB(name, cat, args);
+ }
+ return -1;
+ }
+
+ @Override
+ public long durationB(String name, long cat, Supplier<String> args) {
+ if (isEnabled(cat)) {
+ return emitDurationB(name, cat, args.get());
}
return -1;
}
@@ -112,24 +127,60 @@
@Override
public void durationE(String name, long cat, long tid, String args) {
if (isEnabled(cat)) {
- Event e = Event.create(name, cat, Phase.E, pid, tid, null, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ emit(name, cat, null, Phase.E, tid, args);
}
}
@Override
- public void durationE(long tid, long cat, String args) {
+ public void durationE(String name, long cat, long tid, Supplier<String> args) {
if (isEnabled(cat)) {
- Event e = Event.create(null, 0L, Phase.E, pid, tid, null, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ emit(name, cat, null, Phase.E, tid, args.get());
+ }
+ }
+
+ @Override
+ public void durationE(long cat, long tid) {
+ if (isEnabled(cat)) {
+ emit(null, 0L, null, Phase.E, tid, null);
+ }
+ }
+
+ @Override
+ public void durationE(long cat, long tid, String args) {
+ if (isEnabled(cat)) {
+ emit(null, 0L, null, Phase.E, tid, args);
+ }
+ }
+
+ @Override
+ public void durationE(long cat, long tid, Supplier<String> args) {
+ if (isEnabled(cat)) {
+ emit(null, 0L, null, Phase.E, tid, args.get());
}
}
@Override
public void instant(String name, long cat, Scope scope, String args) {
if (isEnabled(cat)) {
- Event e = Event.create(name, cat, Phase.i, pid, Thread.currentThread().getId(), scope, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ emit(name, cat, scope, Phase.i, Thread.currentThread().getId(), args);
}
}
+
+ @Override
+ public void instant(String name, long cat, Scope scope, Supplier<String> args) {
+ if (isEnabled(cat)) {
+ emit(name, cat, scope, Phase.i, Thread.currentThread().getId(), args.get());
+ }
+ }
+
+ private long emitDurationB(String name, long cat, String args) {
+ Event e = Event.create(name, cat, Phase.B, PID, Thread.currentThread().getId(), null, args, getRegistry());
+ traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ return e.tid;
+ }
+
+ private void emit(String name, long cat, Scope scope, Phase i, long tid, String args) {
+ Event e = Event.create(name, cat, i, PID, tid, scope, args, getRegistry());
+ traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ }
}
--
To view, visit https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643
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: I040523a73e65a0fd86fff3fff38d2278d83ef65f
Gerrit-Change-Number: 14643
Gerrit-PatchSet: 1
Gerrit-Owner: Michael Blow <mb...@apache.org>
Gerrit-MessageType: newchange
Change in asterixdb[master]: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
Posted by AsterixDB Code Review <do...@asterix-gerrit.ics.uci.edu>.
From Jenkins <je...@fulliautomatix.ics.uci.edu>:
Jenkins has posted comments on this change. ( https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643 )
Change subject: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
......................................................................
Patch Set 1: Integration-Tests-1
Integration Tests Failed
https://asterix-jenkins.ics.uci.edu/job/asterix-gerrit-integration-tests/12845/ : FAILURE
--
To view, visit https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643
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: I040523a73e65a0fd86fff3fff38d2278d83ef65f
Gerrit-Change-Number: 14643
Gerrit-PatchSet: 1
Gerrit-Owner: Michael Blow <mb...@apache.org>
Gerrit-Reviewer: Jenkins <je...@fulliautomatix.ics.uci.edu>
Gerrit-Comment-Date: Wed, 22 Dec 2021 14:40:00 +0000
Gerrit-HasComments: No
Gerrit-Has-Labels: Yes
Gerrit-MessageType: comment
Change in asterixdb[master]: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
Posted by AsterixDB Code Review <do...@asterix-gerrit.ics.uci.edu>.
From Michael Blow <mb...@apache.org>:
Michael Blow has uploaded this change for review. ( https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643 )
Change subject: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
......................................................................
[NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
Change-Id: I040523a73e65a0fd86fff3fff38d2278d83ef65f
---
M asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
M asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
M hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
M hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
M hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
11 files changed, 125 insertions(+), 26 deletions(-)
git pull ssh://asterix-gerrit.ics.uci.edu:29418/asterixdb refs/changes/43/14643/1
diff --git a/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java b/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
index 37e589a..7bc3b4f 100644
--- a/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
+++ b/asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
@@ -162,7 +162,7 @@
@Override
public void nextFrame(ByteBuffer buffer) throws HyracksDataException {
- long tid = tracer.durationB("Ingestion-Store", traceCategory, null);
+ long tid = tracer.durationB("Ingestion-Store", traceCategory);
try {
if (hasMessage) {
FeedUtils.processFeedMessage(buffer, message, fta);
@@ -172,7 +172,7 @@
LOGGER.log(Level.WARN, "Failure Processing a frame at store side", e);
throw HyracksDataException.create(e);
} finally {
- tracer.durationE(tid, traceCategory, null);
+ tracer.durationE(traceCategory, tid);
}
}
diff --git a/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java b/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
index 591ff9a..1e7f4b7 100644
--- a/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
+++ b/asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
@@ -459,7 +459,7 @@
if (tracer.isEnabled(traceCategory) && lastRecordInTimeStamp > 0 && indexHelper != null
&& indexHelper.getIndexInstance() != null) {
tracer.instant("UpsertClose", traceCategory, Scope.t,
- "{\"last-record-in\":\"" + DATE_FORMAT.get().format(new Date(lastRecordInTimeStamp))
+ () -> "{\"last-record-in\":\"" + DATE_FORMAT.get().format(new Date(lastRecordInTimeStamp))
+ "\", \"index\":" + indexHelper.getIndexInstance().toString() + "}");
}
} catch (Throwable traceFailure) {
diff --git a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
index c774317..8c9cbfb 100644
--- a/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
+++ b/hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
@@ -710,7 +710,7 @@
@Override
public void run() {
try {
- tracer.instant("CurrentTime", traceCategory, Tracer.Scope.p, Tracer.dateTimeStamp());
+ tracer.instant("CurrentTime", traceCategory, ITracer.Scope.p, Tracer::dateTimeStamp);
} catch (Exception e) {
LOGGER.log(Level.WARN, "Exception tracing current time", e);
}
diff --git a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
index 59ab2f4..e1acaee 100644
--- a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
+++ b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
@@ -116,7 +116,7 @@
try {
flush(writer);
} finally {
- tracer.durationE(tid, traceCategory, args);
+ tracer.durationE(traceCategory, tid, args);
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
index ec45437..39e223b 100644
--- a/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
+++ b/hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
@@ -157,7 +157,7 @@
flushedBytes = frameTupleAppender.getBuffer().capacity();
long tid = tracer.durationB(name, cat, args);
frameTupleAppender.write(writer, true);
- tracer.durationE(tid, cat, args);
+ tracer.durationE(cat, tid, args);
if (!frameTupleAppender.append(tupleAccessor, tIndex)) {
throw HyracksDataException.create(ErrorCode.TUPLE_CANNOT_FIT_INTO_EMPTY_FRAME,
tupleAccessor.getTupleLength(tIndex));
diff --git a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
index dfb1a17..0813a00 100644
--- a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
+++ b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
@@ -171,7 +171,7 @@
public void logPerformanceCounters(int tupleCount) {
if (isTracingEnabled()) {
tracer.instant("store-counters", traceCategory, Scope.t,
- "{\"count\":" + tupleCount + ",\"enter-exit-duration-ns\":" + enterExitTime + "}");
+ () -> "{\"count\":" + tupleCount + ",\"enter-exit-duration-ns\":" + enterExitTime + "}");
resetCounters();
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
index 92fa135..950a8e5 100644
--- a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
+++ b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
@@ -262,7 +262,7 @@
}
if (inactiveMemoryComponentsToBeCleanedUp != null) {
for (ILSMMemoryComponent c : inactiveMemoryComponentsToBeCleanedUp) {
- tracer.instant(c.toString(), traceCategory, Scope.p, lsmIndex.toString());
+ tracer.instant(c.toString(), traceCategory, Scope.p, lsmIndex::toString);
c.cleanup();
synchronized (opTracker) {
c.reset();
diff --git a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
index 4ab57c5..eb48f82 100644
--- a/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
+++ b/hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
@@ -58,7 +58,7 @@
final long traceCategory = tracer.getRegistry().get(TraceUtils.INDEX_IO_OPERATIONS);
if (tracer.isEnabled(traceCategory)) {
tracer.instant("schedule-" + ioOpName, traceCategory, Scope.p,
- "{\"path\": \"" + ioOp.getTarget().getRelativePath() + "\"}");
+ () -> "{\"path\": \"" + ioOp.getTarget().getRelativePath() + "\"}");
return new TracedIOOperation(ioOp, tracer, traceCategory);
}
return ioOp;
@@ -91,11 +91,11 @@
@Override
public LSMIOOperationStatus call() throws HyracksDataException {
final String name = getTarget().getRelativePath();
- final long tid = tracer.durationB(name, traceCategory, null);
+ final long tid = tracer.durationB(name, traceCategory);
try {
return ioOp.call();
} finally {
- tracer.durationE(ioOp.getIOOpertionType().name().toLowerCase(), traceCategory, tid, "{\"size\":"
+ tracer.durationE(ioOp.getIOOpertionType().name().toLowerCase(), traceCategory, tid, () -> "{\"size\":"
+ getTarget().getFile().length() + ", \"path\": \"" + ioOp.getTarget().getRelativePath() + "\"}");
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
index 9adac04..9b316ba 100644
--- a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
+++ b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
@@ -45,6 +45,10 @@
@Override
protected void afterExecute(Runnable r, Throwable t) {
super.afterExecute(r, t);
- Thread.currentThread().setName(savedName.get());
+ try {
+ Thread.currentThread().setName(savedName.get());
+ } finally {
+ savedName.remove();
+ }
}
}
diff --git a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
index 908dc1c..6a9aa89 100644
--- a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
+++ b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
@@ -19,6 +19,8 @@
package org.apache.hyracks.util.trace;
+import java.util.function.Supplier;
+
public interface ITracer {
enum Phase {
@@ -83,7 +85,7 @@
}
@Override
- public void durationE(long tid, long cat, String args) {
+ public void durationE(long cat, long tid, String args) {
// nothing to do here
}
@@ -91,6 +93,36 @@
public void instant(String name, long cat, Scope scope, String args) {
// nothing to do here
}
+
+ @Override
+ public long durationB(String name, long cat) {
+ return -1;
+ }
+
+ @Override
+ public long durationB(String name, long cat, Supplier<String> args) {
+ return -1;
+ }
+
+ @Override
+ public void durationE(long cat, long tid) {
+ // nothing to do here
+ }
+
+ @Override
+ public void durationE(long cat, long tid, Supplier<String> args) {
+ // nothing to do here
+ }
+
+ @Override
+ public void durationE(String name, long cat, long tid, Supplier<String> args) {
+ // nothing to do here
+ }
+
+ @Override
+ public void instant(String name, long cat, Scope scope, Supplier<String> args) {
+ // nothing to do here
+ }
};
String getName();
@@ -101,14 +133,26 @@
boolean isEnabled(long cat);
+ long durationB(String name, long cat);
+
long durationB(String name, long cat, String args);
- void durationE(long tid, long cat, String args);
+ long durationB(String name, long cat, Supplier<String> args);
+
+ void durationE(long cat, long tid);
+
+ void durationE(long cat, long tid, String args);
+
+ void durationE(long cat, long tid, Supplier<String> args);
void durationE(String name, long cat, long tid, String args);
+ void durationE(String name, long cat, long tid, Supplier<String> args);
+
void instant(String name, long cat, Scope scope, String args);
+ void instant(String name, long cat, Scope scope, Supplier<String> args);
+
@Override
String toString();
}
diff --git a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
index c1c38cf..1359e60 100644
--- a/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
+++ b/hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
@@ -23,6 +23,7 @@
import java.text.SimpleDateFormat;
import java.util.Arrays;
import java.util.Date;
+import java.util.function.Supplier;
import org.apache.hyracks.util.PidHelper;
import org.apache.logging.log4j.Level;
@@ -44,7 +45,7 @@
private long categories;
private final TraceCategoryRegistry registry;
- private static final long pid = PidHelper.getPid();
+ private static final long PID = PidHelper.getPid();
public Tracer(String name, long categories, TraceCategoryRegistry registry) {
final String traceLoggerName = Tracer.class.getName() + ".Traces." + name;
@@ -53,7 +54,7 @@
this.categories = categories;
this.registry = registry;
final long traceCategory = getRegistry().get(TraceUtils.TRACER);
- instant("Trace-Start", traceCategory, Scope.p, dateTimeStamp());
+ instant("Trace-Start", traceCategory, Scope.p, Tracer::dateTimeStamp);
}
public Tracer(String name, String[] categories, TraceCategoryRegistry registry) {
@@ -100,11 +101,25 @@
}
@Override
+ public long durationB(String name, long cat) {
+ if (isEnabled(cat)) {
+ return emitDurationB(name, cat, null);
+ }
+ return -1;
+ }
+
+ @Override
public long durationB(String name, long cat, String args) {
if (isEnabled(cat)) {
- Event e = Event.create(name, cat, Phase.B, pid, Thread.currentThread().getId(), null, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
- return e.tid;
+ return emitDurationB(name, cat, args);
+ }
+ return -1;
+ }
+
+ @Override
+ public long durationB(String name, long cat, Supplier<String> args) {
+ if (isEnabled(cat)) {
+ return emitDurationB(name, cat, args.get());
}
return -1;
}
@@ -112,24 +127,60 @@
@Override
public void durationE(String name, long cat, long tid, String args) {
if (isEnabled(cat)) {
- Event e = Event.create(name, cat, Phase.E, pid, tid, null, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ emit(name, cat, null, Phase.E, tid, args);
}
}
@Override
- public void durationE(long tid, long cat, String args) {
+ public void durationE(String name, long cat, long tid, Supplier<String> args) {
if (isEnabled(cat)) {
- Event e = Event.create(null, 0L, Phase.E, pid, tid, null, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ emit(name, cat, null, Phase.E, tid, args.get());
+ }
+ }
+
+ @Override
+ public void durationE(long cat, long tid) {
+ if (isEnabled(cat)) {
+ emit(null, 0L, null, Phase.E, tid, null);
+ }
+ }
+
+ @Override
+ public void durationE(long cat, long tid, String args) {
+ if (isEnabled(cat)) {
+ emit(null, 0L, null, Phase.E, tid, args);
+ }
+ }
+
+ @Override
+ public void durationE(long cat, long tid, Supplier<String> args) {
+ if (isEnabled(cat)) {
+ emit(null, 0L, null, Phase.E, tid, args.get());
}
}
@Override
public void instant(String name, long cat, Scope scope, String args) {
if (isEnabled(cat)) {
- Event e = Event.create(name, cat, Phase.i, pid, Thread.currentThread().getId(), scope, args, getRegistry());
- traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ emit(name, cat, scope, Phase.i, Thread.currentThread().getId(), args);
}
}
+
+ @Override
+ public void instant(String name, long cat, Scope scope, Supplier<String> args) {
+ if (isEnabled(cat)) {
+ emit(name, cat, scope, Phase.i, Thread.currentThread().getId(), args.get());
+ }
+ }
+
+ private long emitDurationB(String name, long cat, String args) {
+ Event e = Event.create(name, cat, Phase.B, PID, Thread.currentThread().getId(), null, args, getRegistry());
+ traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ return e.tid;
+ }
+
+ private void emit(String name, long cat, Scope scope, Phase i, long tid, String args) {
+ Event e = Event.create(name, cat, i, PID, tid, scope, args, getRegistry());
+ traceLog.log(TRACE_LOG_LEVEL, e.toJson());
+ }
}
--
To view, visit https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643
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: I040523a73e65a0fd86fff3fff38d2278d83ef65f
Gerrit-Change-Number: 14643
Gerrit-PatchSet: 1
Gerrit-Owner: Michael Blow <mb...@apache.org>
Gerrit-MessageType: newchange
Change in asterixdb[master]: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
Posted by AsterixDB Code Review <do...@asterix-gerrit.ics.uci.edu>.
From Michael Blow <mb...@apache.org>:
Hello Jenkins,
I'd like you to reexamine a change. Please visit
https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643
to look at the new patch set (#2).
Change subject: [NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
......................................................................
[NO ISSUE][HYR][MISC] Add option to provide tracer args via Suppliers
Change-Id: I040523a73e65a0fd86fff3fff38d2278d83ef65f
---
M asterixdb/asterix-external-data/src/main/java/org/apache/asterix/external/operators/FeedMetaStoreNodePushable.java
M asterixdb/asterix-runtime/src/main/java/org/apache/asterix/runtime/operators/LSMPrimaryUpsertOperatorNodePushable.java
M hyracks-fullstack/hyracks/hyracks-control/hyracks-control-nc/src/main/java/org/apache/hyracks/control/nc/NodeControllerService.java
M hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/io/AbstractFrameAppender.java
M hyracks-fullstack/hyracks/hyracks-dataflow-common/src/main/java/org/apache/hyracks/dataflow/common/comm/util/FrameUtils.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/AbstractLSMIndexOperationContext.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/LSMHarness.java
M hyracks-fullstack/hyracks/hyracks-storage-am-lsm-common/src/main/java/org/apache/hyracks/storage/am/lsm/common/impls/TracedIOOperation.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/MaintainedThreadNameExecutorService.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/ITracer.java
M hyracks-fullstack/hyracks/hyracks-util/src/main/java/org/apache/hyracks/util/trace/Tracer.java
M hyracks-fullstack/hyracks/hyracks-util/src/test/java/org/apache/hyracks/util/trace/TraceTest.java
12 files changed, 145 insertions(+), 32 deletions(-)
git pull ssh://asterix-gerrit.ics.uci.edu:29418/asterixdb refs/changes/43/14643/2
--
To view, visit https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/14643
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: I040523a73e65a0fd86fff3fff38d2278d83ef65f
Gerrit-Change-Number: 14643
Gerrit-PatchSet: 2
Gerrit-Owner: Michael Blow <mb...@apache.org>
Gerrit-Reviewer: Jenkins <je...@fulliautomatix.ics.uci.edu>
Gerrit-MessageType: newpatchset