TINKERPOP-1686 Refactored DefaultTraversalMetrics There seems to be some weird problem in gryo serialization for this class that is difficult to reproduce. It seemed to have something to do with nested maps or perhaps TreeMap, but I wasn't able to easily isolate it to create a bug report to Kryo. All I know is that these changes made the serialization failure (a buffer underflow) go away. It also fixed a problem where deserialization with GraphSON did not allow the getMetrics(int) method to work.
Project: http://git-wip-us.apache.org/repos/asf/tinkerpop/repo Commit: http://git-wip-us.apache.org/repos/asf/tinkerpop/commit/e2d474a2 Tree: http://git-wip-us.apache.org/repos/asf/tinkerpop/tree/e2d474a2 Diff: http://git-wip-us.apache.org/repos/asf/tinkerpop/diff/e2d474a2 Branch: refs/heads/TINKERPOP-1686 Commit: e2d474a2d839618c55a60c4b4033bad35402f6e5 Parents: 4088440 Author: Stephen Mallette <[email protected]> Authored: Wed Jun 7 15:06:10 2017 -0400 Committer: Stephen Mallette <[email protected]> Committed: Wed Jun 28 08:31:46 2017 -0400 ---------------------------------------------------------------------- .../traversal/util/DefaultTraversalMetrics.java | 216 +++++++------------ 1 file changed, 81 insertions(+), 135 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/tinkerpop/blob/e2d474a2/gremlin-core/src/main/java/org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversalMetrics.java ---------------------------------------------------------------------- diff --git a/gremlin-core/src/main/java/org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversalMetrics.java b/gremlin-core/src/main/java/org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversalMetrics.java index ed2aa2d..4047c3b 100644 --- a/gremlin-core/src/main/java/org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversalMetrics.java +++ b/gremlin-core/src/main/java/org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversalMetrics.java @@ -23,6 +23,7 @@ import org.apache.tinkerpop.gremlin.process.traversal.Step; import org.apache.tinkerpop.gremlin.process.traversal.Traversal; import org.apache.tinkerpop.gremlin.process.traversal.step.TraversalParent; import org.apache.tinkerpop.gremlin.process.traversal.step.util.ProfileStep; +import org.javatuples.Pair; import java.io.Serializable; import java.util.ArrayList; @@ -31,7 +32,6 @@ import java.util.HashMap; import java.util.LinkedHashMap; import java.util.List; import java.util.Map; -import java.util.TreeMap; import java.util.concurrent.TimeUnit; /** @@ -40,6 +40,7 @@ import java.util.concurrent.TimeUnit; * * @author Bob Briody (http://bobbriody.com) * @author Marko A. Rodriguez (http://markorodriguez.com) + * @author Stephen Mallette (http://stephen.genoprime.com) */ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializable { /** @@ -47,8 +48,10 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ */ private static final String[] HEADERS = {"Step", "Count", "Traversers", "Time (ms)", "% Dur"}; - private final Map<String, MutableMetrics> metrics = new HashMap<>(); - private final TreeMap<Integer, String> indexToLabelMap = new TreeMap<>(); + /** + * {@link ImmutableMetrics} indexed by their step identifier. + */ + private final Map<String, ImmutableMetrics> stepIndexedMetrics = new HashMap<>(); /** * A computed value representing the total time spent on all steps. @@ -56,9 +59,9 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ private long totalStepDuration; /** - * The metrics that are reported to the caller of profile() which are computed once all metrics have been gathered. + * {@link ImmutableMetrics} indexed by their step position. */ - private Map<String, ImmutableMetrics> computedMetrics; + private Map<Integer, ImmutableMetrics> positionIndexedMetrics = new LinkedHashMap<>(); /** * Determines if final metrics have been computed @@ -71,10 +74,12 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ /** * This is only a convenient constructor needed for GraphSON deserialization. */ - public DefaultTraversalMetrics(final long totalStepDurationNs, final List<MutableMetrics> metricsMap) { - this.totalStepDuration = totalStepDurationNs; - this.computedMetrics = new LinkedHashMap<>(metricsMap.size()); - metricsMap.forEach(metric -> this.computedMetrics.put(metric.getId(), metric.getImmutableClone())); + public DefaultTraversalMetrics(final long totalStepDurationNs, final List<MutableMetrics> orderedMetrics) { + totalStepDuration = totalStepDurationNs; + for (int ix = 0; ix < orderedMetrics.size(); ix++) { + stepIndexedMetrics.put(orderedMetrics.get(ix).getId(), orderedMetrics.get(ix).getImmutableClone()); + positionIndexedMetrics.put(ix, orderedMetrics.get(ix).getImmutableClone()); + } } @Override @@ -84,18 +89,17 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ @Override public Metrics getMetrics(final int index) { - // adjust index to account for the injected profile steps - return this.computedMetrics.get(this.indexToLabelMap.get(index)); + return this.positionIndexedMetrics.get(index); } @Override public Metrics getMetrics(final String id) { - return this.computedMetrics.get(id); + return this.stepIndexedMetrics.get(id); } @Override public Collection<ImmutableMetrics> getMetrics() { - return this.computedMetrics.values(); + return this.positionIndexedMetrics.values(); } /** @@ -115,7 +119,7 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ sb.append("\n============================================================================================================="); - appendMetrics(this.computedMetrics.values(), sb, 0); + appendMetrics(this.positionIndexedMetrics.values(), sb, 0); // Append total duration sb.append(String.format("%n%50s %21s %11s %15.3f %8s", @@ -131,137 +135,34 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ public synchronized void setMetrics(final Traversal.Admin traversal, final boolean onGraphComputer) { if (finalized) throw new IllegalStateException("Metrics have been finalized and cannot be modified"); finalized = true; - addTopLevelMetrics(traversal, onGraphComputer); handleNestedTraversals(traversal, null, onGraphComputer); - computeTotals(); - } - - private void appendMetrics(final Collection<? extends Metrics> metrics, final StringBuilder sb, final int indent) { - // Append each StepMetric's row. indexToLabelMap values are ordered by index. - for (Metrics m : metrics) { - String rowName = m.getName(); - - // Handle indentation - for (int ii = 0; ii < indent; ii++) { - rowName = " " + rowName; - } - // Abbreviate if necessary - rowName = StringUtils.abbreviate(rowName, 50); - - // Grab the values - final Long itemCount = m.getCount(ELEMENT_COUNT_ID); - final Long traverserCount = m.getCount(TRAVERSER_COUNT_ID); - final Double percentDur = (Double) m.getAnnotation(PERCENT_DURATION_KEY); - - // Build the row string - - sb.append(String.format("%n%-50s", rowName)); - - if (itemCount != null) { - sb.append(String.format(" %21d", itemCount)); - } else { - sb.append(String.format(" %21s", "")); - } - - if (traverserCount != null) { - sb.append(String.format(" %11d", traverserCount)); - } else { - sb.append(String.format(" %11s", "")); - } - - sb.append(String.format(" %15.3f", m.getDuration(TimeUnit.MICROSECONDS) / 1000.0)); - - if (percentDur != null) { - sb.append(String.format(" %8.2f", percentDur)); - } - - // process any annotations - final Map<String,Object> annotations = m.getAnnotations(); - if (!annotations.isEmpty()) { - // ignore the PERCENT_DURATION_KEY as that is a TinkerPop annotation that is displayed by default - annotations.entrySet().stream().filter(kv -> !kv.getKey().equals(PERCENT_DURATION_KEY)).forEach(kv -> { - final String prefix = " \\_"; - final String separator = "="; - final String k = prefix + StringUtils.abbreviate(kv.getKey(), 30); - final int valueIndentLen = separator.length() + k.length() + indent; - final int leftover = 110 - valueIndentLen; - - final String[] splitValues = splitOnSize(kv.getValue().toString(), leftover); - for (int ix = 0; ix < splitValues.length; ix++) { - // the first lines gets the annotation prefix. the rest are indented to the separator - if (ix == 0) { - sb.append(String.format("%n%s", k + separator + splitValues[ix])); - } else { - sb.append(String.format("%n%s", padLeft(splitValues[ix], valueIndentLen - 1))); - } - } - }); - } - - appendMetrics(m.getNested(), sb, indent + 1); - } + addTopLevelMetrics(traversal, onGraphComputer); } - private static String[] splitOnSize(final String text, final int size) { - final String[] ret = new String[(text.length() + size - 1) / size]; - - int counter = 0; - for (int start = 0; start < text.length(); start += size) { - ret[counter] = text.substring(start, Math.min(text.length(), start + size)); - counter++; - } + private void addTopLevelMetrics(final Traversal.Admin traversal, final boolean onGraphComputer) { + this.totalStepDuration = 0; - return ret; - } + final List<ProfileStep> profileSteps = TraversalHelper.getStepsOfClass(ProfileStep.class, traversal); + final List<Pair<Integer, MutableMetrics>> tempMetrics = new ArrayList<>(profileSteps.size()); - private static String padLeft(final String text, final int amountToPad) { - // not sure why this method needed to exist. stupid string format stuff and commons utilities wouldn't - // work for some reason in the context this method was used above. - String newText = text; - for (int ix = 0; ix < amountToPad; ix++) { - newText = " " + newText; - } - return newText; - } + for (int ii = 0; ii < profileSteps.size(); ii++) { + // The index is necessary to ensure that step order is preserved after a merge. + final ProfileStep step = profileSteps.get(ii); + final MutableMetrics stepMetrics = onGraphComputer ? traversal.getSideEffects().get(step.getId()) : step.getMetrics(); - private void computeTotals() { - // Create temp list of ordered metrics - final List<MutableMetrics> tempMetrics = new ArrayList<>(this.metrics.size()); - for (final String label : this.indexToLabelMap.values()) { - // The indexToLabelMap is sorted by index (key) - tempMetrics.add(this.metrics.get(label).clone()); + this.totalStepDuration += stepMetrics.getDuration(MutableMetrics.SOURCE_UNIT); + tempMetrics.add(Pair.with(ii, stepMetrics.clone())); } - // Calculate total duration - this.totalStepDuration = 0; - tempMetrics.forEach(metric -> this.totalStepDuration += metric.getDuration(MutableMetrics.SOURCE_UNIT)); - - // Assign %'s tempMetrics.forEach(m -> { - final double dur = m.getDuration(TimeUnit.NANOSECONDS) * 100.d / this.totalStepDuration; - m.setAnnotation(PERCENT_DURATION_KEY, dur); + final double dur = m.getValue1().getDuration(TimeUnit.NANOSECONDS) * 100.d / this.totalStepDuration; + m.getValue1().setAnnotation(PERCENT_DURATION_KEY, dur); }); - // Store immutable instances of the calculated metrics - this.computedMetrics = new LinkedHashMap<>(this.metrics.size()); - tempMetrics.forEach(it -> this.computedMetrics.put(it.getId(), it.getImmutableClone())); - } - - private void addTopLevelMetrics(final Traversal.Admin traversal, final boolean onGraphComputer) { - final List<ProfileStep> profileSteps = TraversalHelper.getStepsOfClass(ProfileStep.class, traversal); - for (int ii = 0; ii < profileSteps.size(); ii++) { - // The index is necessary to ensure that step order is preserved after a merge. - final ProfileStep step = profileSteps.get(ii); - if (onGraphComputer) { - final MutableMetrics stepMetrics = traversal.getSideEffects().get(step.getId()); - this.indexToLabelMap.put(ii, stepMetrics.getId()); - this.metrics.put(stepMetrics.getId(), stepMetrics); - } else { - final MutableMetrics stepMetrics = step.getMetrics(); - this.indexToLabelMap.put(ii, stepMetrics.getId()); - this.metrics.put(stepMetrics.getId(), stepMetrics); - } - } + tempMetrics.forEach(p -> { + this.stepIndexedMetrics.put(p.getValue1().getId(), p.getValue1().getImmutableClone()); + this.positionIndexedMetrics.put(p.getValue0(), p.getValue1().getImmutableClone()); + }); } private void handleNestedTraversals(final Traversal.Admin traversal, final MutableMetrics parentMetrics, final boolean onGraphComputer) { @@ -315,7 +216,7 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ // Grab the values final Long itemCount = m.getCount(ELEMENT_COUNT_ID); final Long traverserCount = m.getCount(TRAVERSER_COUNT_ID); - Double percentDur = (Double) m.getAnnotation(PERCENT_DURATION_KEY); + final Double percentDur = (Double) m.getAnnotation(PERCENT_DURATION_KEY); // Build the row string @@ -339,7 +240,52 @@ public final class DefaultTraversalMetrics implements TraversalMetrics, Serializ sb.append(String.format(" %8.2f", percentDur)); } + // process any annotations + final Map<String,Object> annotations = m.getAnnotations(); + if (!annotations.isEmpty()) { + // ignore the PERCENT_DURATION_KEY as that is a TinkerPop annotation that is displayed by default + annotations.entrySet().stream().filter(kv -> !kv.getKey().equals(PERCENT_DURATION_KEY)).forEach(kv -> { + final String prefix = " \\_"; + final String separator = "="; + final String k = prefix + StringUtils.abbreviate(kv.getKey(), 30); + final int valueIndentLen = separator.length() + k.length() + indent; + final int leftover = 110 - valueIndentLen; + + final String[] splitValues = splitOnSize(kv.getValue().toString(), leftover); + for (int ix = 0; ix < splitValues.length; ix++) { + // the first lines gets the annotation prefix. the rest are indented to the separator + if (ix == 0) { + sb.append(String.format("%n%s", k + separator + splitValues[ix])); + } else { + sb.append(String.format("%n%s", padLeft(splitValues[ix], valueIndentLen - 1))); + } + } + }); + } + appendMetrics(m.getNested(), sb, indent + 1); } } + + private static String[] splitOnSize(final String text, final int size) { + final String[] ret = new String[(text.length() + size - 1) / size]; + + int counter = 0; + for (int start = 0; start < text.length(); start += size) { + ret[counter] = text.substring(start, Math.min(text.length(), start + size)); + counter++; + } + + return ret; + } + + private static String padLeft(final String text, final int amountToPad) { + // not sure why this method needed to exist. stupid string format stuff and commons utilities wouldn't + // work for some reason in the context this method was used above. + String newText = text; + for (int ix = 0; ix < amountToPad; ix++) { + newText = " " + newText; + } + return newText; + } }
