diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/execute/MutationState.java b/phoenix-core-client/src/main/java/org/apache/phoenix/execute/MutationState.java index 46a8057ab1e..d6b84ae4c91 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/execute/MutationState.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/execute/MutationState.java @@ -1724,7 +1724,7 @@ public static MutationMetricQueue.MutationMetric updateMutationBatchFailureMetri numUpsertMutationsInBatch, allUpsertsMutations ? 1 : 0, numDeleteMutationsInBatch, - allDeletesMutations ? 1 : 0, 0); + allDeletesMutations ? 1 : 0, 0, 0, 0, 0, 0, 0, 0); } /** @@ -1807,7 +1807,7 @@ static MutationMetric getCommittedMutationsMetric( committedDeleteMutationCounter, committedTotalMutationBytes, numFailedPhase3Mutations, - 0, 0, 0, 0, mutationBatchCounter); + 0, 0, 0, 0, mutationBatchCounter, 0, 0, 0, 0, 0, 0); } private void filterIndexCheckerMutations(Map> mutationMap, diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java b/phoenix-core-client/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java index 8c0e5cafe9f..014bbd54a46 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java @@ -43,6 +43,7 @@ import static org.apache.phoenix.monitoring.MetricType.UPSERT_SQL_COUNTER; import static org.apache.phoenix.monitoring.MetricType.UPSERT_SQL_QUERY_TIME; import static org.apache.phoenix.monitoring.MetricType.UPSERT_SUCCESS_SQL_COUNTER; +import static org.apache.phoenix.monitoring.MutationMetricQueue.MutationMetric; import java.io.File; import java.io.IOException; @@ -221,6 +222,7 @@ import org.apache.phoenix.util.ClientUtil; import org.apache.phoenix.util.CDCUtil; import org.apache.phoenix.util.CursorUtil; +import org.apache.phoenix.util.EnvironmentEdge; import org.apache.phoenix.util.PhoenixKeyValueUtil; import org.apache.phoenix.util.EnvironmentEdgeManager; import org.apache.phoenix.util.LogUtil; @@ -606,6 +608,7 @@ private Pair executeMutation(final CompilableStatement stmt, new CallRunner.CallableThrowable, SQLException>() { @Override public Pair call() throws SQLException { + final long startExecuteMutationTime = EnvironmentEdgeManager.timeMarkerInNanos(); boolean success = false; String tableName = null; boolean isUpsert = false; @@ -613,8 +616,9 @@ public Pair call() throws SQLException { boolean isDelete = false; MutationState state = null; MutationPlan plan = null; - final long startExecuteMutationTime = EnvironmentEdgeManager.currentTimeMillis(); clearResultSet(); + long mutationPlanCreationTimeInNs = 0; + long mutationPlanExecutionTimeInNs = 0; try { PhoenixConnection conn = getConnection(); if (conn.getQueryServices().isUpgradeRequired() && !conn.isRunningUpgrade() @@ -624,6 +628,7 @@ public Pair call() throws SQLException { state = connection.getMutationState(); isUpsert = stmt instanceof ExecutableUpsertStatement; isDelete = stmt instanceof ExecutableDeleteStatement; + long mutationPlanCreationStartTimeMarker = EnvironmentEdgeManager.timeMarkerInNanos(); if (isDelete && connection.getAutoCommit() && returnResult == ReturnResult.ROW) { // used only if single row deletion needs to atomically @@ -635,6 +640,8 @@ public Pair call() throws SQLException { plan = stmt.compilePlan(PhoenixStatement.this, Sequence.ValueOp.VALIDATE_SEQUENCE); } + mutationPlanCreationTimeInNs = EnvironmentEdgeManager.timeMarkerInNanos() - + mutationPlanCreationStartTimeMarker; isAtomicUpsert = isUpsert && ((ExecutableUpsertStatement)stmt).getOnDupKeyPairs() != null; if (plan.getTargetRef() != null && plan.getTargetRef().getTable() != null) { if (!Strings.isNullOrEmpty(plan.getTargetRef().getTable().getPhysicalName().toString())) { @@ -648,7 +655,10 @@ public Pair call() throws SQLException { state.sendUncommitted(tableRefs); state.checkpointIfNeccessary(plan); checkIfDDLStatementandMutationState(stmt, state); + long mutationPlanExecutionStartTimeMarker = EnvironmentEdgeManager.timeMarkerInNanos(); MutationState lastState = plan.execute(); + mutationPlanExecutionTimeInNs = EnvironmentEdgeManager.timeMarkerInNanos() - + mutationPlanExecutionStartTimeMarker; state.join(lastState); // Unfortunately, JDBC uses an int for update count, so we // just max out at Integer.MAX_VALUE @@ -718,8 +728,10 @@ public Pair call() throws SQLException { MUTATION_SQL_COUNTER, 1); // Only count dml operations if (isUpsert || isDelete) { - long executeMutationTimeSpent = - EnvironmentEdgeManager.currentTimeMillis() - startExecuteMutationTime; + long executeMutationTimeSpentInNs = + EnvironmentEdgeManager.timeMarkerInNanos() - startExecuteMutationTime; + // This will ensure existing use cases of metrics are not broken. + long executeMutationTimeSpent = EnvironmentEdge.convertTimeInNsToMs(executeMutationTimeSpentInNs); TableMetricsManager.updateMetricsMethod(tableName, isUpsert ? UPSERT_SQL_COUNTER : DELETE_SQL_COUNTER, 1); @@ -731,6 +743,22 @@ public Pair call() throws SQLException { TableMetricsManager.updateMetricsMethod(tableName, ATOMIC_UPSERT_SQL_QUERY_TIME, executeMutationTimeSpent); } + MutationMetric stagedMutationMetric; + if (isUpsert) { + stagedMutationMetric = getUncommittedMutationMetric( + mutationPlanCreationTimeInNs, + mutationPlanExecutionTimeInNs, 0, 0, + executeMutationTimeSpentInNs, 0); + } + else { + stagedMutationMetric = getUncommittedMutationMetric( + 0, 0, + mutationPlanCreationTimeInNs, + mutationPlanExecutionTimeInNs, 0, + executeMutationTimeSpentInNs); + } + state.getMutationMetricQueue().addMetricsForTable( + tableName, stagedMutationMetric); if (success) { TableMetricsManager.updateMetricsMethod(tableName, isUpsert ? @@ -753,6 +781,7 @@ public Pair call() throws SQLException { state.addExecuteMutationTime( executeMutationTimeSpent, tableName); } + } } @@ -773,6 +802,26 @@ public Pair call() throws SQLException { } } + /** + * Get mutation metrics for executeMutation call i.e. before the mutation are committed. + * All the times are in nano seconds. + * @param upsertMutationPlanCreationTime Time taken to create the upsert mutation plan. + * @param upsertMutationPlanExecutionTime Time taken to execute the upsert mutation plan. + * @param deleteMutationPlanCreationTime Time taken to create the delete mutation plan. + * @param deleteMutationPlanExecutionTime Time taken to execute the delete mutation plan. + * @param upsertExecuteMutationTime Time taken by upsert in executeMutation call. + * @param deleteExecuteMutationTime Time taken by delete in executeMutation call. + * @return MutationMetric object. + */ + private MutationMetric getUncommittedMutationMetric(long upsertMutationPlanCreationTime, long upsertMutationPlanExecutionTime, + long deleteMutationPlanCreationTime, long deleteMutationPlanExecutionTime, + long upsertExecuteMutationTime, long deleteExecuteMutationTime) { + return new MutationMetric(0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, + upsertMutationPlanCreationTime, upsertMutationPlanExecutionTime, + deleteMutationPlanCreationTime, deleteMutationPlanExecutionTime, + upsertExecuteMutationTime, deleteExecuteMutationTime); + } + /** * Get different Result if the row is atomically deleted. * diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MetricType.java b/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MetricType.java index 40b7932a28c..c51139bc14c 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MetricType.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MetricType.java @@ -88,6 +88,18 @@ public enum MetricType { DELETE_BATCH_FAILED_COUNTER("dbfc", "Number of delete mutation batches that failed to be committed", LogLevel.OFF, PLong.INSTANCE), + UPSERT_PLAN_CREATION_TIME("upct", "Time taken to create the upsert mutation plan in ns", + LogLevel.OFF, PLong.INSTANCE), + UPSERT_PLAN_EXECUTION_TIME("upet", "Time taken to execute the upsert mutation plan in ns", + LogLevel.OFF, PLong.INSTANCE), + UPSERT_EXECUTE_MUTATION_TIME("uemt", "Time taken by upsert in executeMutation in ns", + LogLevel.OFF, PLong.INSTANCE), + DELETE_PLAN_CREATION_TIME("dpct", "Time taken to create the delete mutation plan in ns", + LogLevel.OFF, PLong.INSTANCE), + DELETE_PLAN_EXECUTION_TIME("dpet", "Time taken to execute the delete mutation plan in ns", + LogLevel.OFF, PLong.INSTANCE), + DELETE_EXECUTE_MUTATION_TIME("demt", "Time taken by delete in executeMutation in ns", + LogLevel.OFF, PLong.INSTANCE), MUTATION_BATCH_COUNTER("mbc", "Number of mutation batches committed " + "in a commit call", LogLevel.OFF, PLong.INSTANCE), diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MutationMetricQueue.java b/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MutationMetricQueue.java index d42a10190b8..61c5136c589 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MutationMetricQueue.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/MutationMetricQueue.java @@ -21,14 +21,20 @@ import static org.apache.phoenix.monitoring.MetricType.DELETE_BATCH_FAILED_COUNTER; import static org.apache.phoenix.monitoring.MetricType.DELETE_BATCH_FAILED_SIZE; import static org.apache.phoenix.monitoring.MetricType.DELETE_COMMIT_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_EXECUTE_MUTATION_TIME; import static org.apache.phoenix.monitoring.MetricType.DELETE_MUTATION_BYTES; import static org.apache.phoenix.monitoring.MetricType.DELETE_MUTATION_SQL_COUNTER; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_EXECUTION_TIME; import static org.apache.phoenix.monitoring.MetricType.MUTATION_BATCH_COUNTER; import static org.apache.phoenix.monitoring.MetricType.MUTATION_BATCH_FAILED_SIZE; import static org.apache.phoenix.monitoring.MetricType.MUTATION_BATCH_SIZE; import static org.apache.phoenix.monitoring.MetricType.MUTATION_BYTES; import static org.apache.phoenix.monitoring.MetricType.MUTATION_COMMIT_TIME; import static org.apache.phoenix.monitoring.MetricType.INDEX_COMMIT_FAILURE_SIZE; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_EXECUTE_MUTATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_EXECUTION_TIME; import static org.apache.phoenix.monitoring.MetricType.UPSERT_BATCH_FAILED_COUNTER; import static org.apache.phoenix.monitoring.MetricType.UPSERT_BATCH_FAILED_SIZE; import static org.apache.phoenix.monitoring.MetricType.UPSERT_COMMIT_TIME; @@ -96,6 +102,24 @@ public Map> aggregate() { publishedMetricsForTable.put(metric.getDeleteBatchFailedCounter().getMetricType(), metric.getDeleteBatchFailedCounter().getValue()); publishedMetricsForTable.put(metric.getMutationBatchCounter().getMetricType(), metric.getMutationBatchCounter().getValue()); + publishedMetricsForTable.put( + metric.getUpsertMutationPlanCreationTime().getMetricType(), + metric.getUpsertMutationPlanCreationTime().getValue()); + publishedMetricsForTable.put( + metric.getUpsertMutationPlanExecutionTime().getMetricType(), + metric.getUpsertMutationPlanExecutionTime().getValue()); + publishedMetricsForTable.put( + metric.getDeleteMutationPlanCreationTime().getMetricType(), + metric.getDeleteMutationPlanCreationTime().getValue()); + publishedMetricsForTable.put( + metric.getDeleteMutationPlanExecutionTime().getMetricType(), + metric.getDeleteMutationPlanExecutionTime().getValue()); + publishedMetricsForTable.put( + metric.getUpsertExecuteMutationTime().getMetricType(), + metric.getUpsertExecuteMutationTime().getValue()); + publishedMetricsForTable.put( + metric.getDeleteExecuteMutationTime().getMetricType(), + metric.getDeleteExecuteMutationTime().getValue()); } return publishedMetrics; } @@ -129,17 +153,35 @@ public static class MutationMetric { private final CombinableMetric mutationBatchCounter = new CombinableMetricImpl(MUTATION_BATCH_COUNTER); + private final CombinableMetric upsertMutationPlanCreationTime = + new CombinableMetricImpl(UPSERT_PLAN_CREATION_TIME); + private final CombinableMetric upsertMutationPlanExecutionTime = + new CombinableMetricImpl(UPSERT_PLAN_EXECUTION_TIME); + private final CombinableMetric deleteMutationPlanCreationTime = + new CombinableMetricImpl(DELETE_PLAN_CREATION_TIME); + private final CombinableMetric deleteMutationPlanExecutionTime = + new CombinableMetricImpl(DELETE_PLAN_EXECUTION_TIME); + private final CombinableMetric upsertExecuteMutationTime = + new CombinableMetricImpl(UPSERT_EXECUTE_MUTATION_TIME); + private final CombinableMetric deleteExecuteMutationTime = + new CombinableMetricImpl(DELETE_EXECUTE_MUTATION_TIME); + public static final MutationMetric EMPTY_METRIC = - new MutationMetric(0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0); + new MutationMetric(0,0,0,0, 0, 0,0,0,0,0,0,0,0,0,0, 0, 0, 0, 0, 0, 0, 0); public MutationMetric(long numMutations, long upsertMutationsSizeBytes, - long deleteMutationsSizeBytes, long commitTimeForUpserts, long commitTimeForAtomicUpserts, - long commitTimeForDeletes, long numFailedMutations, long upsertMutationSqlCounterSuccess, - long deleteMutationSqlCounterSuccess, long totalMutationBytes, - long numOfPhase3Failed, long upsertBatchFailedSize, - long upsertBatchFailedCounter, long deleteBatchFailedSize, - long deleteBatchFailedCounter, long mutationBatchCounter) { + long deleteMutationsSizeBytes, long commitTimeForUpserts, long commitTimeForAtomicUpserts, + long commitTimeForDeletes, long numFailedMutations, long upsertMutationSqlCounterSuccess, + long deleteMutationSqlCounterSuccess, long totalMutationBytes, + long numOfPhase3Failed, long upsertBatchFailedSize, + long upsertBatchFailedCounter, long deleteBatchFailedSize, + long deleteBatchFailedCounter, long mutationBatchCounter, + long upsertMutationPlanCreationTime, + long upsertMutationPlanExecutionTime, + long deleteMutationPlanCreationTime, + long deleteMutationPlanExecutionTime, long upsertExecuteMutationTime, + long deleteExecuteMutationTime) { this.numMutations.change(numMutations); this.totalCommitTimeForUpserts.change(commitTimeForUpserts); this.totalCommitTimeForAtomicUpserts.change(commitTimeForAtomicUpserts); @@ -157,6 +199,12 @@ public MutationMetric(long numMutations, long upsertMutationsSizeBytes, this.deleteBatchFailedSize.change(deleteBatchFailedSize); this.deleteBatchFailedCounter.change(deleteBatchFailedCounter); this.mutationBatchCounter.change(mutationBatchCounter); + this.upsertMutationPlanCreationTime.change(upsertMutationPlanCreationTime); + this.upsertMutationPlanExecutionTime.change(upsertMutationPlanExecutionTime); + this.deleteMutationPlanCreationTime.change(deleteMutationPlanCreationTime); + this.deleteMutationPlanExecutionTime.change(deleteMutationPlanExecutionTime); + this.upsertExecuteMutationTime.change(upsertExecuteMutationTime); + this.deleteExecuteMutationTime.change(deleteExecuteMutationTime); } public CombinableMetric getTotalCommitTimeForUpserts() { @@ -225,6 +273,30 @@ public CombinableMetric getMutationBatchCounter() { return mutationBatchCounter; } + public CombinableMetric getUpsertMutationPlanCreationTime() { + return upsertMutationPlanCreationTime; + } + + public CombinableMetric getUpsertMutationPlanExecutionTime() { + return upsertMutationPlanExecutionTime; + } + + public CombinableMetric getDeleteMutationPlanCreationTime() { + return deleteMutationPlanCreationTime; + } + + public CombinableMetric getDeleteMutationPlanExecutionTime() { + return deleteMutationPlanExecutionTime; + } + + public CombinableMetric getUpsertExecuteMutationTime() { + return upsertExecuteMutationTime; + } + + public CombinableMetric getDeleteExecuteMutationTime() { + return deleteExecuteMutationTime; + } + public void combineMetric(MutationMetric other) { this.numMutations.combine(other.numMutations); this.totalCommitTimeForUpserts.combine(other.totalCommitTimeForUpserts); @@ -243,6 +315,12 @@ public void combineMetric(MutationMetric other) { this.deleteBatchFailedSize.combine(other.deleteBatchFailedSize); this.deleteBatchFailedCounter.combine(other.deleteBatchFailedCounter); this.mutationBatchCounter.combine(other.mutationBatchCounter); + this.upsertMutationPlanCreationTime.combine(other.upsertMutationPlanCreationTime); + this.upsertMutationPlanExecutionTime.combine(other.upsertMutationPlanExecutionTime); + this.deleteMutationPlanCreationTime.combine(other.deleteMutationPlanCreationTime); + this.deleteMutationPlanExecutionTime.combine(other.deleteMutationPlanExecutionTime); + this.upsertExecuteMutationTime.combine(other.upsertExecuteMutationTime); + this.deleteExecuteMutationTime.combine(other.deleteExecuteMutationTime); } } diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/TableClientMetrics.java b/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/TableClientMetrics.java index 6832775919c..2c75de0993c 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/TableClientMetrics.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/monitoring/TableClientMetrics.java @@ -78,6 +78,12 @@ import static org.apache.phoenix.monitoring.MetricType.ATOMIC_UPSERT_COMMIT_TIME; import static org.apache.phoenix.monitoring.MetricType.ATOMIC_UPSERT_SQL_COUNTER; import static org.apache.phoenix.monitoring.MetricType.ATOMIC_UPSERT_SQL_QUERY_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_EXECUTION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_EXECUTION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_EXECUTE_MUTATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_EXECUTE_MUTATION_TIME; /** * This is used by TableMetricsManager class to store instance of @@ -139,7 +145,13 @@ public enum TableMetrics { TABLE_NUM_SYSTEM_TABLE_RPC_FAILURES(NUM_SYSTEM_TABLE_RPC_FAILURES), TABLE_NUM_METADATA_LOOKUP_FAILURES(NUM_METADATA_LOOKUP_FAILURES), TABLE_TIME_SPENT_IN_SYSTEM_TABLE_RPC_CALLS(TIME_SPENT_IN_SYSTEM_TABLE_RPC_CALLS), - TABLE_MUTATION_BATCH_SUCCESS_COUNTER(MUTATION_BATCH_COUNTER); + TABLE_MUTATION_BATCH_SUCCESS_COUNTER(MUTATION_BATCH_COUNTER), + TABLE_UPSERT_PLAN_CREATION_TIME(UPSERT_PLAN_CREATION_TIME), + TABLE_UPSERT_PLAN_EXECUTION_TIME(UPSERT_PLAN_EXECUTION_TIME), + TABLE_DELETE_PLAN_CREATION_TIME(DELETE_PLAN_CREATION_TIME), + TABLE_DELETE_PLAN_EXECUTION_TIME(DELETE_PLAN_EXECUTION_TIME), + TABLE_UPSERT_EXECUTE_MUTATION_TIME(UPSERT_EXECUTE_MUTATION_TIME), + TABLE_DELETE_EXECUTE_MUTATION_TIME(DELETE_EXECUTE_MUTATION_TIME); private MetricType metricType; private PhoenixTableMetric metric; diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/util/DefaultEnvironmentEdge.java b/phoenix-core-client/src/main/java/org/apache/phoenix/util/DefaultEnvironmentEdge.java index 6a1e0755846..dcb353566b2 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/util/DefaultEnvironmentEdge.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/util/DefaultEnvironmentEdge.java @@ -31,4 +31,9 @@ public long currentTime() { return System.currentTimeMillis(); } + @Override + public long nanoTime() { + return System.nanoTime(); + } + } diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdge.java b/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdge.java index 31e8a4c0d6a..d24d842c6e8 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdge.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdge.java @@ -32,4 +32,23 @@ public abstract class EnvironmentEdge implements org.apache.hadoop.hbase.util.En */ @Override abstract public long currentTime(); + + /** + * This method can be only be used to measure elapsed time. The method returns a time marker + * and if we subtract any two time markers returned by this method, then we get time elapsed + * b/w those two markers in nano seconds. For further details refer to documentation of + * {@link System#nanoTime()}. + * @return a time marker in nano seconds + */ + public long nanoTime() { + return convertTimeInMsToNs(currentTime()); + } + + public static long convertTimeInMsToNs(long value) { + return value * 1000000; + } + + public static long convertTimeInNsToMs(long value) { + return value / 1000000; + } } diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdgeManager.java b/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdgeManager.java index c5e1a63476c..519ea6a47f5 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdgeManager.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/util/EnvironmentEdgeManager.java @@ -75,4 +75,14 @@ public static void injectEdge(EnvironmentEdge edge) { public static long currentTimeMillis() { return getDelegate().currentTime(); } + + /** + * Defers to the delegate and calls the {@link EnvironmentEdge#nanoTime()} method. + * Subtracting two markers will give you the elapsed time in nanos. + * + * @return marker in nano seconds + */ + public static long timeMarkerInNanos() { + return getDelegate().nanoTime(); + } } diff --git a/phoenix-core-client/src/main/java/org/apache/phoenix/util/ManualEnvironmentEdge.java b/phoenix-core-client/src/main/java/org/apache/phoenix/util/ManualEnvironmentEdge.java index 169e3131caa..ca5079621af 100644 --- a/phoenix-core-client/src/main/java/org/apache/phoenix/util/ManualEnvironmentEdge.java +++ b/phoenix-core-client/src/main/java/org/apache/phoenix/util/ManualEnvironmentEdge.java @@ -19,18 +19,32 @@ public class ManualEnvironmentEdge extends EnvironmentEdge { // Sometimes 0 ts might have a special value, so lets start with 1 + // value is in Nano seconds protected long value = 1L; public void setValue(long newValue) { - value = newValue; + value = convertTimeInMsToNs(newValue); } public void incrementValue(long addedValue) { - value += addedValue; + value += convertTimeInMsToNs(addedValue); } @Override public long currentTime() { + return convertTimeInNsToMs(this.value); + } + + @Override + public long nanoTime() { return this.value; } -} \ No newline at end of file + + public void setValueInNs(long newValue) { + this.value = newValue; + } + + public void incrementValueInNs(long newValue) { + this.value += newValue; + } +} diff --git a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/BasePhoenixMetricsIT.java b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/BasePhoenixMetricsIT.java index 5a83bfa6d57..88a78d87abf 100644 --- a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/BasePhoenixMetricsIT.java +++ b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/BasePhoenixMetricsIT.java @@ -114,8 +114,7 @@ static void assertMutationMetrics(String tableName, int numRows, boolean isUpser String t = entry.getKey(); assertEquals("Table names didn't match!", tableName, t); Map p = entry.getValue(); - - assertEquals("There should have been seventeen metrics", 17, p.size()); + assertEquals("There should have been 23 metrics", 23, p.size()); boolean mutationBatchSizePresent = false; boolean mutationCommitTimePresent = false; @@ -133,6 +132,12 @@ static void assertMutationMetrics(String tableName, int numRows, boolean isUpser boolean upsertCommitTimeCounterPresent = false; boolean deleteCommitTimeCounterPresent = false; boolean mutationBatchCounterPresent = false; + boolean upsertPlanCreationTimePresent = false; + boolean upsertPlanExecutionTimePresent = false; + boolean upsertExecuteMutationTimePresent = false; + boolean deletePlanCreationTimePresent = false; + boolean deletePlanExecutionTimePresent = false; + boolean deleteExecuteMutationTimePresent = false; for (Map.Entry metric : p.entrySet()) { MetricType metricType = metric.getKey(); long metricValue = metric.getValue(); @@ -212,6 +217,68 @@ else if (metricType.equals(MetricType.MUTATION_BATCH_COUNTER)) { metricValue > 0); mutationBatchCounterPresent = true; } + else if (metricType.equals(MetricType.UPSERT_PLAN_CREATION_TIME)) { + if (isUpsert) { + assertTrue("Upsert plan creation time counter should be greater " + + "than zero", metricValue > 0); + } else { + assertEquals("Zero upsert plan creation time counter expected", + 0, metricValue); + } + upsertPlanCreationTimePresent = true; + } + else if (metricType.equals(MetricType.UPSERT_PLAN_EXECUTION_TIME)) { + if (isUpsert) { + assertTrue("Upsert plan execution time counter should be greater " + + "than zero", metricValue > 0); + } else { + assertEquals("Zero upsert plan execution time counter expected", + 0, metricValue); + } + upsertPlanExecutionTimePresent = true; + } + else if (metricType.equals(MetricType.UPSERT_EXECUTE_MUTATION_TIME)) { + if (isUpsert) { + assertTrue("Upsert execute mutation time counter should be greater " + + "than zero", metricValue > 0); + } else { + assertEquals("Zero upsert execute mutation time counter expected", + 0, metricValue); + } + upsertExecuteMutationTimePresent = true; + } + else if (metricType.equals(MetricType.DELETE_PLAN_CREATION_TIME)) { + if (! isUpsert) { + assertTrue("Delete plan creation time counter should be greater " + + "than zero", metricValue > 0); + } else { + assertEquals("Zero delete plan creation time counter expected", + 0, metricValue); + + } + deletePlanCreationTimePresent = true; + } + else if (metricType.equals(MetricType.DELETE_PLAN_EXECUTION_TIME)) { + if (! isUpsert) { + assertTrue("Delete plan execution time counter should be greater " + + "than zero", metricValue > 0); + } else { + assertEquals("Zero delete plan execution time counter expected", + 0, metricValue); + + } + deletePlanExecutionTimePresent = true; + } + else if (metricType.equals(MetricType.DELETE_EXECUTE_MUTATION_TIME)) { + if (! isUpsert) { + assertTrue("Delete execute mutation time counter should be greater " + + "than zero", metricValue > 0); + } else { + assertEquals("Zero delete execute mutation time counter expected", + 0, metricValue); + } + deleteExecuteMutationTimePresent = true; + } } assertTrue(mutationBatchSizePresent); assertTrue(mutationCommitTimePresent); @@ -229,6 +296,12 @@ else if (metricType.equals(MetricType.MUTATION_BATCH_COUNTER)) { assertTrue(upsertCommitTimeCounterPresent); assertTrue(deleteCommitTimeCounterPresent); assertTrue(mutationBatchCounterPresent); + assertTrue(upsertPlanCreationTimePresent); + assertTrue(upsertPlanExecutionTimePresent); + assertTrue(upsertExecuteMutationTimePresent); + assertTrue(deletePlanCreationTimePresent); + assertTrue(deletePlanExecutionTimePresent); + assertTrue(deleteExecuteMutationTimePresent); } } diff --git a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixLoggingMetricsIT.java b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixLoggingMetricsIT.java index 5691a8ca6b2..1d8d2bbd402 100644 --- a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixLoggingMetricsIT.java +++ b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixLoggingMetricsIT.java @@ -31,7 +31,9 @@ import java.sql.ResultSet; import java.sql.SQLException; import java.sql.Statement; +import java.util.HashSet; import java.util.Map; +import java.util.Set; import static org.junit.Assert.assertNull; import static org.junit.Assert.assertTrue; @@ -153,12 +155,22 @@ public void testPhoenixMetricsLoggedOnClose() throws Exception { String upsertSelect = "UPSERT INTO " + tableName2 + " SELECT * FROM " + tableName1; loggedConn.createStatement().executeUpdate(upsertSelect); - // Autocommit is turned off by default - // Hence mutation metrics are not expected during connection close loggedConn.close(); - assertTrue("Mutation write metrics are not logged for " + tableName2, - mutationWriteMetricsMap.size() == 0); - assertTrue("Mutation read metrics for not found for " + tableName1, + Set mutationMetricsFromExecuteUpdate = new HashSet<>(); + mutationMetricsFromExecuteUpdate.add(MetricType.UPSERT_PLAN_CREATION_TIME); + mutationMetricsFromExecuteUpdate.add(MetricType.UPSERT_PLAN_EXECUTION_TIME); + mutationMetricsFromExecuteUpdate.add(MetricType.UPSERT_EXECUTE_MUTATION_TIME); + // No mutations were sent from client to server but we will collect metrics from + // executeUpdate() call so, maximum 3 metrics should be non-zero + int unexpectedMetrics = 0; + for (Map.Entry entry: mutationWriteMetricsMap.get(tableName2).entrySet()) { + if (! mutationMetricsFromExecuteUpdate.contains(entry.getKey()) && entry.getValue() > 0) { + unexpectedMetrics++; + } + } + assertTrue("Unexpected metrics were found for " + tableName2 + " : " + + mutationWriteMetricsMap.get(tableName2), unexpectedMetrics == 0); + assertTrue("Mutation read metrics not found for " + tableName1, mutationReadMetricsMap.get(tableName1).size() > 0); assertReadMetricsForMutatingSql(tableName1, 1, mutationReadMetricsMap); diff --git a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixMetricsIT.java b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixMetricsIT.java index f3495fef914..a49bbe414e3 100644 --- a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixMetricsIT.java +++ b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixMetricsIT.java @@ -40,6 +40,9 @@ import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_TASK_EXECUTION_TIME; import static org.apache.phoenix.monitoring.MetricType.COUNT_MILLS_BETWEEN_NEXTS; import static org.apache.phoenix.monitoring.MetricType.DELETE_COMMIT_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_EXECUTE_MUTATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_EXECUTION_TIME; import static org.apache.phoenix.monitoring.MetricType.MEMORY_CHUNK_BYTES; import static org.apache.phoenix.monitoring.MetricType.MUTATION_BATCH_COUNTER; import static org.apache.phoenix.monitoring.MetricType.MUTATION_COMMIT_TIME; @@ -49,6 +52,9 @@ import static org.apache.phoenix.monitoring.MetricType.TASK_EXECUTION_TIME; import static org.apache.phoenix.monitoring.MetricType.TASK_QUEUE_WAIT_TIME; import static org.apache.phoenix.monitoring.MetricType.UPSERT_COMMIT_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_EXECUTE_MUTATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_EXECUTION_TIME; import static org.apache.phoenix.util.PhoenixRuntime.TENANT_ID_ATTRIB; import static org.apache.phoenix.util.PhoenixRuntime.UPSERT_BATCH_SIZE_ATTRIB; import static org.junit.Assert.assertEquals; @@ -133,6 +139,9 @@ public class PhoenixMetricsIT extends BasePhoenixMetricsIT { private static final List mutationMetricsToSkip = Lists.newArrayList(MUTATION_COMMIT_TIME, UPSERT_COMMIT_TIME, DELETE_COMMIT_TIME, + UPSERT_PLAN_CREATION_TIME, UPSERT_PLAN_EXECUTION_TIME, + UPSERT_EXECUTE_MUTATION_TIME, DELETE_PLAN_CREATION_TIME, + DELETE_PLAN_EXECUTION_TIME, DELETE_EXECUTE_MUTATION_TIME, MUTATION_BATCH_COUNTER); private static final List readMetricsToSkip = Lists.newArrayList(TASK_QUEUE_WAIT_TIME, TASK_EXECUTION_TIME, TASK_END_TO_END_TIME, @@ -393,7 +402,9 @@ static void createTableAndRunUpsertSelect(String destTableName, String sourceTab PhoenixRuntime.clearTableLevelMetrics(); } try (Statement stmt = conn.createStatement()) { + System.out.println("Start test"); stmt.executeUpdate(String.format(UPSERT_SELECT_DML, destTableName, sourceTableName)); + System.out.println("End test"); } if (commit) { conn.commit(); @@ -510,7 +521,7 @@ public void testMetricsForUpsert() throws Exception { String t = entry.getKey(); assertEquals("Table names didn't match!", tableName, t); Map p = entry.getValue(); - assertEquals("There should have been seventeen metrics", 17, p.size()); + assertEquals("There should have been 23 metrics", 23, p.size()); boolean mutationBatchSizePresent = false; boolean mutationCommitTimePresent = false; boolean mutationBytesPresent = false; diff --git a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixTableLevelMetricsIT.java b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixTableLevelMetricsIT.java index 1a1280e12ac..b8241552739 100644 --- a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixTableLevelMetricsIT.java +++ b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/PhoenixTableLevelMetricsIT.java @@ -39,6 +39,7 @@ import org.apache.phoenix.query.ConnectionQueryServicesImpl; import org.apache.phoenix.query.QueryServices; import org.apache.phoenix.query.QueryServicesTestImpl; +import org.apache.phoenix.util.DefaultEnvironmentEdge; import org.apache.phoenix.util.EnvironmentEdge; import org.apache.phoenix.util.EnvironmentEdgeManager; import org.apache.phoenix.util.InstanceResolver; @@ -66,6 +67,12 @@ import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_MUTATION_BYTES; import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_QUERY_TIME; import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_SCAN_BYTES; +import static org.apache.phoenix.monitoring.MetricType.DELETE_EXECUTE_MUTATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.DELETE_PLAN_EXECUTION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_EXECUTE_MUTATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_CREATION_TIME; +import static org.apache.phoenix.monitoring.MetricType.UPSERT_PLAN_EXECUTION_TIME; import static org.apache.phoenix.monitoring.MetricType.MUTATION_BATCH_COUNTER; import static org.apache.phoenix.monitoring.MetricType.NUM_SYSTEM_TABLE_RPC_SUCCESS; import static org.apache.phoenix.monitoring.MetricType.DELETE_AGGREGATE_FAILURE_SQL_COUNTER; @@ -120,6 +127,7 @@ import static org.apache.phoenix.monitoring.PhoenixMetricsIT.doDeleteAllFromTable; import static org.apache.phoenix.query.QueryServices.ENABLE_SERVER_UPSERT_SELECT; import static org.apache.phoenix.util.DelayedOrFailingRegionServer.INJECTED_EXCEPTION_STRING; +import static org.apache.phoenix.util.EnvironmentEdge.convertTimeInMsToNs; import static org.apache.phoenix.util.PhoenixRuntime.JDBC_PROTOCOL_SEPARATOR; import static org.apache.phoenix.util.PhoenixRuntime.UPSERT_BATCH_SIZE_ATTRIB; import static org.apache.phoenix.util.PhoenixRuntime.clearTableLevelMetrics; @@ -155,6 +163,8 @@ public class PhoenixTableLevelMetricsIT extends BaseTest { private static final String UPSERT_DML = "UPSERT INTO %s VALUES (?, ?)"; private static final String KEY = "key"; private static final String VALUE = "value"; + private static final int CLOCK_DELAY = 1; + private static final int MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION = 5; private static boolean failExecuteQueryAndClientSideDeletes; private static long injectDelay; private static HBaseTestingUtility hbaseTestUtil; @@ -193,6 +203,11 @@ public class PhoenixTableLevelMetricsIT extends BaseTest { initAndRegisterTestDriver(url, new ReadOnlyProps(props.entrySet().iterator())); } + private void useCustomClock() { + MyClock clock = new MyClock(10, CLOCK_DELAY); + EnvironmentEdgeManager.injectEdge(clock); + } + @AfterClass public static void tearDownMiniCluster() { try { if (hbaseTestUtil != null) { @@ -335,9 +350,15 @@ static void assertSelectQueryTableMetrics(final String tableName, final boolean * @param writeMutMetrics write mutation metrics object * @param conn connection object. Note: this method must be called after connection close * since that's where we populate table-level write metrics + * @param expectedSystemCatalogMetric True if metrics for calls to SYSTEM.CATALOG table were captured + * and should be validated * @param expectedMutationBatchCount expected number of mutation batches per commit call - - */ + * @param expectedMinMutationPlanCreationTime minimum expected time taken to create mutation plan + * @param expectedMinMutationPlanExecutionTime minimum expected time taken to execute mutation plan + * @param expectedMinExecuteMutationTime minimum expected time taken by executeMutation() call + * + * @throws SQLException + */ private static void assertMutationTableMetrics(final boolean isUpsert, final String tableName, final long expectedUpsertOrDeleteSuccessSqlCt, final long expectedUpsertOrDeleteFailedSqlCt, @@ -348,7 +369,11 @@ private static void assertMutationTableMetrics(final boolean isUpsert, final Str final long expectedUpsertOrDeleteAggregateSuccessCt, final long expectedUpsertOrDeleteAggregateFailureCt, final Map writeMutMetrics, final Connection conn, - final boolean expectedSystemCatalogMetric, final long expectedMutationBatchCount) + final boolean expectedSystemCatalogMetric, + final long expectedMutationBatchCount, + final long expectedMinMutationPlanCreationTime, + final long expectedMinMutationPlanExecutionTime, + final long expectedMinExecuteMutationTime) throws SQLException { assertTrue(conn != null && conn.isClosed()); assertFalse(hasMutationBeenExplicitlyCommitted && writeMutMetrics == null); @@ -371,6 +396,21 @@ private static void assertMutationTableMetrics(final boolean isUpsert, final Str expectedUpsertOrDeleteFailedSqlCt, CompareOp.EQ); assertMetricValue(metric, isUpsert ? UPSERT_SQL_QUERY_TIME : DELETE_SQL_QUERY_TIME, expectedMinUpsertOrDeleteSqlQueryTime, CompareOp.GTEQ); + assertMetricValue(metric, isUpsert ? UPSERT_PLAN_CREATION_TIME : DELETE_PLAN_CREATION_TIME, + writeMutMetrics.get(isUpsert ? UPSERT_PLAN_CREATION_TIME : DELETE_PLAN_CREATION_TIME), + CompareOp.EQ); + assertMetricValue(metric, isUpsert ? UPSERT_PLAN_CREATION_TIME : DELETE_PLAN_CREATION_TIME, + expectedMinMutationPlanCreationTime, CompareOp.GTEQ); + assertMetricValue(metric, isUpsert ? UPSERT_PLAN_EXECUTION_TIME : DELETE_PLAN_EXECUTION_TIME, + writeMutMetrics.get(isUpsert ? UPSERT_PLAN_EXECUTION_TIME : DELETE_PLAN_EXECUTION_TIME), + CompareOp.EQ); + assertMetricValue(metric, isUpsert ? UPSERT_PLAN_EXECUTION_TIME : DELETE_PLAN_EXECUTION_TIME, + expectedMinMutationPlanExecutionTime, CompareOp.GTEQ); + assertMetricValue(metric, isUpsert ? UPSERT_EXECUTE_MUTATION_TIME : DELETE_EXECUTE_MUTATION_TIME, + writeMutMetrics.get(isUpsert ? UPSERT_EXECUTE_MUTATION_TIME : DELETE_EXECUTE_MUTATION_TIME), + CompareOp.EQ); + assertMetricValue(metric, isUpsert ? UPSERT_EXECUTE_MUTATION_TIME : DELETE_EXECUTE_MUTATION_TIME, + expectedMinExecuteMutationTime, CompareOp.GTEQ); if(expectedSystemCatalogMetric){ assertMetricValue(metric,NUM_SYSTEM_TABLE_RPC_SUCCESS,0,CompareOp.GT); assertMetricValue(metric,TIME_SPENT_IN_SYSTEM_TABLE_RPC_CALLS,0,CompareOp.GT); @@ -700,6 +740,7 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa } @Test public void testTableLevelMetricsForUpsert() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 10000; Connection conn = null; @@ -722,12 +763,19 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa conn.close(); // Must be asserted after connection close since that's where // we populate table-level metrics - assertMutationTableMetrics(true, tableName, numRows, 0, 0, true, numRows, 0, 0, 1, 0, - writeMutMetrics, conn, true, 100); + assertMutationTableMetrics(true, tableName, numRows, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY * numRows, + true, numRows, 0, 0, 1, 0, + writeMutMetrics, conn, true, 100, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, + convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY) * numRows); } } @Test public void testTableLevelMetricsForBatchUpserts() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 20; Connection conn = null; @@ -748,12 +796,19 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(true, tableName, numRows, 0, 0, true, numRows, 0, 0, 1, 0, - writeMutMetrics, conn, true, 1); + assertMutationTableMetrics(true, tableName, numRows, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY * numRows, + true, numRows, 0, 0, 1, 0, + writeMutMetrics, conn, true, 1, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, + convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY) * numRows); } } @Test public void testTableLevelMetricsAutoCommitTrueUpsert() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); String ddl = String.format(CREATE_TABLE_DDL, tableName, 20); int numRows = 10; @@ -789,11 +844,16 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa // mutation commit time since autoCommit was on assertMutationTableMetrics(true, tableName, numRows, 0, writeMutMetrics.get(UPSERT_COMMIT_TIME), true, numRows, 0, 0, numRows, 0, - writeMutMetrics, conn,true, 10); + writeMutMetrics, conn,true, 10, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, + convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY) * numRows); } } @Test public void testTableLevelMetricsforFailingUpsert() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); // Restrict the key to just 2 characters so that we fail later String ddl = String.format(CREATE_TABLE_DDL, tableName, 2); @@ -823,12 +883,19 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa throw exception; } assertNotNull("Failed to get a connection!", conn); + Map + writeMutMetrics = + getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(true, tableName, 0, 1, 0, false, 0, 0, 0, 1, 0, null, conn, true, 0); + assertMutationTableMetrics(true, tableName, 0, 1, 0, false, 0, 0, 0, 1, 0, + writeMutMetrics, conn, true, 0, + convertTimeInMsToNs(CLOCK_DELAY), 0, + convertTimeInMsToNs(3 * CLOCK_DELAY)); } } @Test public void testTableLevelMetricsforUpsertSqlTime() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); String ddl = String.format(CREATE_TABLE_DDL, tableName, 10); int numRows = 10; @@ -863,12 +930,19 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(true, tableName, numRows, 0, delay, true, numRows, 0, 0, 1, - 0, writeMutMetrics, conn, true, 1); + assertMutationTableMetrics(true, tableName, numRows, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * delay * numRows, + true, numRows, 0, 0, 1, + 0, writeMutMetrics, conn, true, 1, + convertTimeInMsToNs(delay) * numRows, + convertTimeInMsToNs(delay) * numRows, + convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * delay) * numRows); } } @Test public void testTableLevelMetricsUpsertCommitFailedWithAutoCommitTrue() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); String ddl = String.format(CREATE_TABLE_DDL, tableName, 10); int numRows = 10; @@ -911,12 +985,18 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(true, tableName, 0, 1, 0, true, 1, 0, 1, 0, 1, - writeMutMetrics, conn, true, 1); + assertMutationTableMetrics(true, tableName, 0, 1, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY, + true, 1, 0, 1, 0, 1, + writeMutMetrics, conn, true, 1, + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY)); } } @Test public void testTableLevelMetricsUpsertCommitFailed() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); String ddl = String.format(CREATE_TABLE_DDL, tableName, 10); int numRows = 10; @@ -962,8 +1042,13 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(true, tableName, numRows, 0, 0, true, numRows, 0, numRows, 0, - 1, writeMutMetrics, conn, true, 1); + assertMutationTableMetrics(true, tableName, numRows, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY, + true, numRows, 0, numRows, 0, + 1, writeMutMetrics, conn, true, 1, + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY)); } } @@ -1002,12 +1087,14 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(true, tableName, numRows, 0, 0, true, numRows, delayRs, 0, 1, - 0, writeMutMetrics, conn, true, 1); + assertMutationTableMetrics(true, tableName, numRows, 0, + 0, true, numRows, delayRs, 0, 1, + 0, writeMutMetrics, conn, true, 1, 0, 0, 0); } } @Test public void testUpsertSelectWithRunOnServerAsTrue() throws SQLException { + useCustomClock(); String srcTableName = generateUniqueName(); String destTableName = generateUniqueName(); int numRows = 10; @@ -1022,13 +1109,31 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa true, true, conn); writeMutMetrics = PhoenixRuntime.getWriteMetricInfoForMutationsSinceLastReset(conn).get(destTableName); } - assertNull(writeMutMetrics); // No commits were done from client to server so, no metrics recorded + // No commits were done from client to server but metrics + // were recorded from executeUpdate() call + assertNotNull(writeMutMetrics); for (PhoenixTableMetric metric: getPhoenixTableClientMetrics().get(destTableName)) { + assertMetricValue(metric, MUTATION_BATCH_COUNTER, + writeMutMetrics.get(MUTATION_BATCH_COUNTER), CompareOp.EQ); assertMetricValue(metric, MUTATION_BATCH_COUNTER, 0, CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, + writeMutMetrics.get(UPSERT_PLAN_CREATION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, + convertTimeInMsToNs(CLOCK_DELAY), CompareOp.GTEQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, + writeMutMetrics.get(UPSERT_PLAN_EXECUTION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, + convertTimeInMsToNs(CLOCK_DELAY), CompareOp.GTEQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, + writeMutMetrics.get(UPSERT_EXECUTE_MUTATION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY), + CompareOp.GTEQ); } } @Test public void testUpsertSelectWithRunOnServerAsFalse() throws SQLException { + useCustomClock(); String srcTableName = generateUniqueName(); String destTableName = generateUniqueName(); int numRows = 10; @@ -1042,16 +1147,31 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa true, true, conn); writeMutMetrics = PhoenixRuntime.getWriteMetricInfoForMutationsSinceLastReset(conn).get(destTableName); } - // Rows were fetched to client from source table and committed to destination table on server + // Rows were fetched to client from source table and committed to destination + // table on server assertNotNull(writeMutMetrics); for (PhoenixTableMetric metric: getPhoenixTableClientMetrics().get(destTableName)) { assertMetricValue(metric, MUTATION_BATCH_COUNTER, writeMutMetrics.get(MUTATION_BATCH_COUNTER), CompareOp.EQ); assertMetricValue(metric, MUTATION_BATCH_COUNTER, 1, CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, + writeMutMetrics.get(UPSERT_PLAN_CREATION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, CompareOp.GTEQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, + writeMutMetrics.get(UPSERT_PLAN_EXECUTION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, CompareOp.GTEQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, + writeMutMetrics.get(UPSERT_EXECUTE_MUTATION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY) * numRows, + CompareOp.GTEQ); } } @Test public void testUpsertWithOverriddenUpsertBatchSize() throws SQLException { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 100; Map writeMutMetrics; @@ -1067,10 +1187,24 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa assertMetricValue(metric, MUTATION_BATCH_COUNTER, writeMutMetrics.get(MUTATION_BATCH_COUNTER), CompareOp.EQ); assertMetricValue(metric, MUTATION_BATCH_COUNTER, 20, CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, + writeMutMetrics.get(UPSERT_PLAN_CREATION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, + writeMutMetrics.get(UPSERT_PLAN_EXECUTION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, + convertTimeInMsToNs(CLOCK_DELAY) * numRows, CompareOp.EQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, + writeMutMetrics.get(UPSERT_EXECUTE_MUTATION_TIME), CompareOp.EQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, convertTimeInMsToNs( + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY) * numRows, + CompareOp.GTEQ); } } @Test public void testTableLevelMetricsForPointDelete() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 15; Connection conn = null; @@ -1096,12 +1230,18 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(false, tableName, 1, 0, 0, true, 1, 0, 0, 1, 0, - writeMutMetrics, conn, false, 1); + assertMutationTableMetrics(false, tableName, 1, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY, + true, 1, 0, 0, 1, 0, + writeMutMetrics, conn, false, 1, + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY)); } } @Test public void testTableLevelMetricsForDeleteAll() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 15; Connection conn = null; @@ -1127,12 +1267,18 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(false, tableName, 1, 0, 0, true, numRows, 0, 0, 1, 0, - writeMutMetrics, conn, false, 1); + assertMutationTableMetrics(false, tableName, 1, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY, + true, numRows, 0, 0, 1, 0, + writeMutMetrics, conn, false, 1, + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY)); } } @Test public void testTableLevelMetricsAutoCommitTrueDelete() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 15; Connection conn = null; @@ -1161,11 +1307,16 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); // When autoCommit = true, deletes happen on the server and so mutation metrics are not - // accumulated for those mutations - assertNull(writeMutMetrics); + // accumulated for those mutations except of the ones collected in executeMutation method + assertNotNull(writeMutMetrics); conn.close(); - assertMutationTableMetrics(false, tableName, 1, 0, 0, false, 0, 0, 0, 0, 0, - writeMutMetrics, conn, false, 1); + assertMutationTableMetrics(false, tableName, 1, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY, + false, 0, 0, 0, 0, 0, + writeMutMetrics, conn, false, 1, + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY)); } } @@ -1209,7 +1360,8 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); assertNull(writeMutMetrics); conn.close(); - assertMutationTableMetrics(false, tableName, 0, 1, 0, false, 0, 0, 0, 0, 1, null, conn, false, 0); + assertMutationTableMetrics(false, tableName, 0, 1, 0, false, 0, 0, 0, 0, 1, null, + conn, false, 0, 0, 0, 0); } } @@ -1248,11 +1400,12 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); assertMutationTableMetrics(false, tableName, 1, 0, injectDelay, true, 1, 0, 0, 1, 0, - writeMutMetrics, conn, false, 1); + writeMutMetrics, conn, false, 1, 0, 0, 0); } } @Test public void testTableLevelMetricsDeleteCommitFailed() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); int numRows = 15; Connection conn = null; @@ -1293,13 +1446,19 @@ private static void assertMetricValue(Metric m, MetricType checkType, long compa writeMutMetrics = getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); - assertMutationTableMetrics(false, tableName, 1, 0, 0, true, numRows, 0, numRows, 0, 1, - writeMutMetrics, conn, false, 1); + assertMutationTableMetrics(false, tableName, 1, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY, + true, numRows, 0, numRows, 0, 1, + writeMutMetrics, conn, false, 1, + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(CLOCK_DELAY), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY)); } } @Test public void testMetricsWithIndexUsage() throws Exception { + useCustomClock(); // Generate unique names for the table and index String dataTable = generateUniqueName(); String indexName = generateUniqueName() + "_IDX"; @@ -1344,6 +1503,22 @@ public void testMetricsWithIndexUsage() throws Exception { writeMutMetrics.get(indexName).get(MUTATION_BATCH_COUNTER), CompareOp.EQ); } } + // Assert that mutation plan creation and execution metrics have captured only for + // data table and not index table + for(PhoenixTableMetric metric: getPhoenixTableClientMetrics().get(dataTable)) { + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, convertTimeInMsToNs(CLOCK_DELAY), + CompareOp.GTEQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, convertTimeInMsToNs(CLOCK_DELAY), + CompareOp.GTEQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY), + CompareOp.GTEQ); + } + for(PhoenixTableMetric metric: getPhoenixTableClientMetrics().get(indexName)) { + assertMetricValue(metric, UPSERT_PLAN_CREATION_TIME, 0, CompareOp.EQ); + assertMetricValue(metric, UPSERT_PLAN_EXECUTION_TIME, 0, CompareOp.EQ); + assertMetricValue(metric, UPSERT_EXECUTE_MUTATION_TIME, 0, CompareOp.EQ); + } // Check if the index is being used try (Connection conn = getConnFromTestDriver()) { @@ -1421,11 +1596,12 @@ public void testMetricsWithIndexUsage() throws Exception { getWriteMetricInfoForMutationsSinceLastReset(conn).get(tableName); conn.close(); assertMutationTableMetrics(false, tableName, 1, 0, 0, true, numRows, delayRs, 0, 1, 0, - writeMutMetrics, conn, false, 1); + writeMutMetrics, conn, false, 1, 0, 0, 0); } } @Test public void testTableLevelMetricsForAtomicUpserts() throws Throwable { + useCustomClock(); String tableName = generateUniqueName(); Connection conn = null; Throwable exception = null; @@ -1462,8 +1638,13 @@ public void testMetricsWithIndexUsage() throws Exception { conn.close(); // 1 regular upsert + numAtomicUpserts // 2 mutations (regular and atomic on the same row in the same batch will be split) - assertMutationTableMetrics(true, tableName, 1 + numAtomicUpserts, 0, 0, true, 2, 0, 0, 2, 0, - writeMutMetrics, conn, false, 2); + assertMutationTableMetrics(true, tableName, 1 + numAtomicUpserts, 0, + MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY * (numAtomicUpserts + 1), + true, 2, 0, 0, 2, 0, + writeMutMetrics, conn, false, 2, + convertTimeInMsToNs(CLOCK_DELAY) * (numAtomicUpserts + 1), + convertTimeInMsToNs(CLOCK_DELAY) * (numAtomicUpserts + 1), + convertTimeInMsToNs(MIN_CLOCK_DELAYS_IN_EXECUTE_MUTATION * CLOCK_DELAY) * (numAtomicUpserts + 1)); assertEquals(numAtomicUpserts, getMetricFromTableMetrics(tableName, ATOMIC_UPSERT_SQL_COUNTER)); assertTrue(getMetricFromTableMetrics(tableName, ATOMIC_UPSERT_COMMIT_TIME) > 0); } diff --git a/phoenix-core/src/test/java/org/apache/phoenix/monitoring/TableMetricsManagerTest.java b/phoenix-core/src/test/java/org/apache/phoenix/monitoring/TableMetricsManagerTest.java index bf92444c623..416aab774ed 100644 --- a/phoenix-core/src/test/java/org/apache/phoenix/monitoring/TableMetricsManagerTest.java +++ b/phoenix-core/src/test/java/org/apache/phoenix/monitoring/TableMetricsManagerTest.java @@ -236,32 +236,38 @@ public void testHistogramMetricsForUpsertMutations() { TableMetricsManager.updateLatencyHistogramForMutations(tableName, 1, true); MutationMetricQueue.MutationMetric metric = new MutationMetricQueue.MutationMetric( 0L, 5L, 0L, 0L, 0L,0L, - 0L, 1L, 0L, 5L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 1L, 0L, 5L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), true); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 2, true); metric = new MutationMetricQueue.MutationMetric(0L, 10L, 0L, 0L, 0L,0L, - 0L, 1L, 0L, 10L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 1L, 0L, 10L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), true); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 4, true); metric = new MutationMetricQueue.MutationMetric(0L, 50L, 0L, 0L, 0L,0L, - 0L, 1L, 0L, 50L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 1L, 0L, 50L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), true); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 5, true); metric = new MutationMetricQueue.MutationMetric(0L, 100L, 0L, 0L, 0L,0L, - 0L, 1L, 0L, 100L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 1L, 0L, 100L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), true); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 6, true); metric = new MutationMetricQueue.MutationMetric(0L, 500L, 0L, 0L, 0L,0L, - 0L, 1L, 0L, 500L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 1L, 0L, 500L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), true); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 8, true); metric = new MutationMetricQueue.MutationMetric(0L, 1000L, 0L, 0L, 0L,0L, - 0L, 1L, 0L, 1000L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 1L, 0L, 1000L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), true); @@ -300,32 +306,38 @@ public void testHistogramMetricsForDeleteMutations() { TableMetricsManager.updateLatencyHistogramForMutations(tableName, 1, false); MutationMetricQueue.MutationMetric metric = new MutationMetricQueue.MutationMetric( 0L, 0L, 5L, 0L, 0L, 0L, - 0L, 0L, 1L, 5L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 0L, 1L, 5L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), false); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 2, false); metric = new MutationMetricQueue.MutationMetric(0L, 0L, 10L, 0L, 0L, 0L, - 0L, 0L, 1L, 10L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 0L, 1L, 10L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), false); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 4, false); metric = new MutationMetricQueue.MutationMetric(0L, 0L, 50L, 0L, 0L, 0L, - 0L, 0L, 1L, 50L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 0L, 1L, 50L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), false); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 5,false); metric = new MutationMetricQueue.MutationMetric(0L, 0L, 100L, 0L, 0L, 0L, - 0L, 0L, 1L, 100L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 0L, 1L, 100L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), false); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 6,false); metric = new MutationMetricQueue.MutationMetric(0L, 0L, 500L, 0L, 0L, 0L, - 0L, 0L, 1L, 500L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 0L, 1L, 500L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), false); TableMetricsManager.updateLatencyHistogramForMutations(tableName, 8, false); metric = new MutationMetricQueue.MutationMetric(0L, 0L, 1000L, 0L, 0L, 0L, - 0L, 0L, 1L, 1000L, 0L, 0L, 0L, 0L, 0L, 0L); + 0L, 0L, 1L, 1000L, 0L, 0L, 0L, 0L, 0L, + 0L, 0L, 0L, 0L, 0L, 0L, 0L); TableMetricsManager.updateSizeHistogramMetricsForMutations(tableName, metric.getTotalMutationsSizeBytes().getValue(), false);