This is an automated email from the ASF dual-hosted git repository. jackietien pushed a commit to branch QueryMetricOpt1.1 in repository https://gitbox.apache.org/repos/asf/iotdb.git
commit 6f19bd0f321f41c582b52a29369a588819317d28 Author: Jackie Tien <[email protected]> AuthorDate: Fri May 19 21:25:10 2023 +0800 [To rel/1.1] Change cost time unit from milli to nano & merge operator metric together in one driver --- .../org/apache/iotdb/db/conf/OperationType.java | 3 +- .../iotdb/db/engine/cache/BloomFilterCache.java | 2 +- .../db/engine/cache/CacheHitRatioMonitor.java | 2 +- .../db/engine/cache/TimeSeriesMetadataCache.java | 10 +- .../iotdb/db/mpp/execution/driver/Driver.java | 15 +- .../mpp/metric/TimeSeriesMetadataCacheMetrics.java | 4 +- .../org/apache/iotdb/db/mpp/plan/Coordinator.java | 2 +- .../db/mpp/plan/execution/IQueryExecution.java | 1 + .../db/mpp/plan/execution/QueryExecution.java | 3 +- .../service/thrift/impl/ClientRPCServiceImpl.java | 200 +++++++++++++-------- 10 files changed, 146 insertions(+), 96 deletions(-) diff --git a/server/src/main/java/org/apache/iotdb/db/conf/OperationType.java b/server/src/main/java/org/apache/iotdb/db/conf/OperationType.java index 4ec94dc2183..866b80cda96 100644 --- a/server/src/main/java/org/apache/iotdb/db/conf/OperationType.java +++ b/server/src/main/java/org/apache/iotdb/db/conf/OperationType.java @@ -26,6 +26,7 @@ public enum OperationType { EXECUTE_QUERY_STATEMENT("executeQueryStatement"), EXECUTE_RAW_DATA_QUERY("executeRawDataQuery"), EXECUTE_LAST_DATA_QUERY("lastDataQueryReqToPhysicalPlan"), + EXECUTE_AGG_QUERY("executeAggregationQuery"), FETCH_RESULTS("fetchResults"), EXECUTE_UPDATE_STATEMENT("executeUpdateStatement"), GET_TIME_ZONE("getTimeZone"), @@ -48,7 +49,7 @@ public enum OperationType { CREATE_SCHEMA_TEMPLATE("createSchemaTemplate"), CHECK_AUTHORITY("checkAuthority"), EXECUTE_NON_QUERY_PLAN("executeNonQueryPlan"), - ; + QUERY_LATENCY("queryLatency"); private final String name; OperationType(String name) { diff --git a/server/src/main/java/org/apache/iotdb/db/engine/cache/BloomFilterCache.java b/server/src/main/java/org/apache/iotdb/db/engine/cache/BloomFilterCache.java index 3980bdf6a62..b1d5b0b5b40 100644 --- a/server/src/main/java/org/apache/iotdb/db/engine/cache/BloomFilterCache.java +++ b/server/src/main/java/org/apache/iotdb/db/engine/cache/BloomFilterCache.java @@ -105,7 +105,7 @@ public class BloomFilterCache { return bloomFilter; } - public double calculateChunkHitRatio() { + public double calculateBloomFilterHitRatio() { return lruCache.stats().hitRate(); } diff --git a/server/src/main/java/org/apache/iotdb/db/engine/cache/CacheHitRatioMonitor.java b/server/src/main/java/org/apache/iotdb/db/engine/cache/CacheHitRatioMonitor.java index c320c26eb73..08cf399f5aa 100644 --- a/server/src/main/java/org/apache/iotdb/db/engine/cache/CacheHitRatioMonitor.java +++ b/server/src/main/java/org/apache/iotdb/db/engine/cache/CacheHitRatioMonitor.java @@ -107,7 +107,7 @@ public class CacheHitRatioMonitor implements CacheHitRatioMonitorMXBean, IServic @Override public double getBloomFilterHitRatio() { - return BloomFilterCache.getInstance().calculateChunkHitRatio(); + return BloomFilterCache.getInstance().calculateBloomFilterHitRatio(); } @Override diff --git a/server/src/main/java/org/apache/iotdb/db/engine/cache/TimeSeriesMetadataCache.java b/server/src/main/java/org/apache/iotdb/db/engine/cache/TimeSeriesMetadataCache.java index 25a2a6b4f6e..569a239a603 100644 --- a/server/src/main/java/org/apache/iotdb/db/engine/cache/TimeSeriesMetadataCache.java +++ b/server/src/main/java/org/apache/iotdb/db/engine/cache/TimeSeriesMetadataCache.java @@ -74,9 +74,6 @@ public class TimeSeriesMetadataCache { private final AtomicLong entryAverageSize = new AtomicLong(0); - private final AtomicLong bloomFilterRequestCount = new AtomicLong(0L); - private final AtomicLong bloomFilterPreventCount = new AtomicLong(0L); - private final Map<String, WeakReference<String>> devices = Collections.synchronizedMap(new WeakHashMap<>()); private static final String SEPARATOR = "$"; @@ -168,9 +165,7 @@ public class TimeSeriesMetadataCache { BloomFilterCache.getInstance() .get(new BloomFilterCache.BloomFilterCacheKey(key.filePath), debug); if (bloomFilter != null) { - bloomFilterRequestCount.incrementAndGet(); if (!bloomFilter.contains(path.getFullPath())) { - bloomFilterPreventCount.incrementAndGet(); if (debug) { DEBUG_LOGGER.info("TimeSeries meta data {} is filter by bloomFilter!", key); } @@ -239,10 +234,7 @@ public class TimeSeriesMetadataCache { } public double calculateBloomFilterHitRatio() { - if (bloomFilterRequestCount.get() == 0L) { - return 1.0d; - } - return bloomFilterPreventCount.get() * 100.0d / bloomFilterRequestCount.get(); + return BloomFilterCache.getInstance().calculateBloomFilterHitRatio(); } /** clear LRUCache. */ diff --git a/server/src/main/java/org/apache/iotdb/db/mpp/execution/driver/Driver.java b/server/src/main/java/org/apache/iotdb/db/mpp/execution/driver/Driver.java index f92650bcde3..ffab0305d47 100644 --- a/server/src/main/java/org/apache/iotdb/db/mpp/execution/driver/Driver.java +++ b/server/src/main/java/org/apache/iotdb/db/mpp/execution/driver/Driver.java @@ -34,7 +34,9 @@ import org.slf4j.LoggerFactory; import javax.annotation.concurrent.GuardedBy; +import java.util.HashMap; import java.util.List; +import java.util.Map; import java.util.Optional; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; @@ -374,15 +376,20 @@ public abstract class Driver implements IDriver { root.close(); sink.setNoMoreTsBlocks(); + Map<String, long[]> operatorType2TotalCost = new HashMap<>(); // record operator execution statistics to metrics List<OperatorContext> operatorContexts = driverContext.getOperatorContexts(); for (OperatorContext operatorContext : operatorContexts) { String operatorType = operatorContext.getOperatorType(); - QUERY_METRICS.recordOperatorExecutionCost( - operatorType, operatorContext.getTotalExecutionTimeInNanos()); - QUERY_METRICS.recordOperatorExecutionCount( - operatorType, operatorContext.getNextCalledCount()); + long[] value = operatorType2TotalCost.computeIfAbsent(operatorType, k -> new long[2]); + value[0] += operatorContext.getTotalExecutionTimeInNanos(); + value[1] += operatorContext.getNextCalledCount(); } + for (Map.Entry<String, long[]> entry : operatorType2TotalCost.entrySet()) { + QUERY_METRICS.recordOperatorExecutionCost(entry.getKey(), entry.getValue()[0]); + QUERY_METRICS.recordOperatorExecutionCount(entry.getKey(), entry.getValue()[1]); + } + } catch (InterruptedException t) { // don't record the stack wasInterrupted = true; diff --git a/server/src/main/java/org/apache/iotdb/db/mpp/metric/TimeSeriesMetadataCacheMetrics.java b/server/src/main/java/org/apache/iotdb/db/mpp/metric/TimeSeriesMetadataCacheMetrics.java index 0f7c8bc0afc..8a3c7eae455 100644 --- a/server/src/main/java/org/apache/iotdb/db/mpp/metric/TimeSeriesMetadataCacheMetrics.java +++ b/server/src/main/java/org/apache/iotdb/db/mpp/metric/TimeSeriesMetadataCacheMetrics.java @@ -43,14 +43,14 @@ public class TimeSeriesMetadataCacheMetrics implements IMetricSet { Metric.CACHE_HIT.toString(), MetricLevel.IMPORTANT, timeSeriesMetadataCache, - l -> timeSeriesMetadataCache.calculateTimeSeriesMetadataHitRatio(), + l -> timeSeriesMetadataCache.calculateTimeSeriesMetadataHitRatio() * 100.0d, Tag.NAME.toString(), "timeSeriesMeta"); metricService.createAutoGauge( Metric.CACHE_HIT.toString(), MetricLevel.IMPORTANT, timeSeriesMetadataCache, - TimeSeriesMetadataCache::calculateBloomFilterHitRatio, + l -> timeSeriesMetadataCache.calculateBloomFilterHitRatio() * 100.0d, Tag.NAME.toString(), "bloomFilter"); } diff --git a/server/src/main/java/org/apache/iotdb/db/mpp/plan/Coordinator.java b/server/src/main/java/org/apache/iotdb/db/mpp/plan/Coordinator.java index 0d444736249..7d00263ff5a 100644 --- a/server/src/main/java/org/apache/iotdb/db/mpp/plan/Coordinator.java +++ b/server/src/main/java/org/apache/iotdb/db/mpp/plan/Coordinator.java @@ -217,7 +217,7 @@ public class Coordinator { queryExecutionMap.remove(queryId); if (queryExecution.isQuery()) { long costTime = queryExecution.getTotalExecutionTime(); - if (costTime >= CONFIG.getSlowQueryThreshold()) { + if (costTime / 1_000_000 >= CONFIG.getSlowQueryThreshold()) { SLOW_SQL_LOGGER.info( "Cost: {} ms, sql is {}", costTime, diff --git a/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/IQueryExecution.java b/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/IQueryExecution.java index e1c9a138952..50c2d2bc253 100644 --- a/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/IQueryExecution.java +++ b/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/IQueryExecution.java @@ -59,6 +59,7 @@ public interface IQueryExecution { void recordExecutionTime(long executionTime); + /** @return cost time in ns */ long getTotalExecutionTime(); Optional<String> getExecuteSQL(); diff --git a/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/QueryExecution.java b/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/QueryExecution.java index b0f6861b55e..b3c72571c80 100644 --- a/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/QueryExecution.java +++ b/server/src/main/java/org/apache/iotdb/db/mpp/plan/execution/QueryExecution.java @@ -131,7 +131,8 @@ public class QueryExecution implements IQueryExecution { private final AtomicBoolean stopped; - private long totalExecutionTime; + // cost time in ns + private long totalExecutionTime = 0; private static final QueryMetricsManager QUERY_METRICS = QueryMetricsManager.getInstance(); diff --git a/server/src/main/java/org/apache/iotdb/db/service/thrift/impl/ClientRPCServiceImpl.java b/server/src/main/java/org/apache/iotdb/db/service/thrift/impl/ClientRPCServiceImpl.java index 4465c6f0284..1d13c2c9275 100644 --- a/server/src/main/java/org/apache/iotdb/db/service/thrift/impl/ClientRPCServiceImpl.java +++ b/server/src/main/java/org/apache/iotdb/db/service/thrift/impl/ClientRPCServiceImpl.java @@ -193,7 +193,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { return RpcUtils.getTSExecuteStatementResp(getNotLoggedInStatus()); } - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); StatementType statementType = null; Throwable t = null; try { @@ -256,15 +256,19 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { t = error; throw error; } finally { - COORDINATOR.recordExecutionTime(queryId, System.currentTimeMillis() - startTime); + long currentOperationCost = System.nanoTime() - startTime; + COORDINATOR.recordExecutionTime(queryId, currentOperationCost); + + // record each operation time cost + if (statementType != null) { + addStatementExecutionLatency( + OperationType.EXECUTE_QUERY_STATEMENT, statementType, currentOperationCost); + } + if (finished) { - if (statementType != null) { - long executionTime = COORDINATOR.getTotalExecutionTime(queryId); - addStatementExecutionLatency( - OperationType.EXECUTE_STATEMENT, - statementType, - executionTime > 0 ? executionTime : System.currentTimeMillis() - startTime); - } + // record total time cost for one query + long executionTime = COORDINATOR.getTotalExecutionTime(queryId); + addQueryLatency(statementType, executionTime > 0 ? executionTime : currentOperationCost); COORDINATOR.cleanupQueryExecution(queryId, t); } SESSION_MANAGER.updateIdleTime(); @@ -279,7 +283,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { if (!SESSION_MANAGER.checkLogin(clientSession)) { return RpcUtils.getTSExecuteStatementResp(getNotLoggedInStatus()); } - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); Throwable t = null; try { Statement s = StatementGenerator.createStatement(req, clientSession.getZoneId()); @@ -332,14 +336,21 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { t = error; throw error; } finally { - COORDINATOR.recordExecutionTime(queryId, System.currentTimeMillis() - startTime); + long currentOperationCost = System.nanoTime() - startTime; + COORDINATOR.recordExecutionTime(queryId, currentOperationCost); + + // record each operation time cost + addStatementExecutionLatency( + OperationType.EXECUTE_RAW_DATA_QUERY, StatementType.QUERY, currentOperationCost); + if (finished) { - addStatementExecutionLatency( - OperationType.EXECUTE_RAW_DATA_QUERY, - StatementType.QUERY, - COORDINATOR.getTotalExecutionTime(queryId)); + // record total time cost for one query + long executionTime = COORDINATOR.getTotalExecutionTime(queryId); + addQueryLatency( + StatementType.QUERY, executionTime > 0 ? executionTime : currentOperationCost); COORDINATOR.cleanupQueryExecution(queryId, t); } + SESSION_MANAGER.updateIdleTime(); } } @@ -352,7 +363,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { if (!SESSION_MANAGER.checkLogin(clientSession)) { return RpcUtils.getTSExecuteStatementResp(getNotLoggedInStatus()); } - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); Throwable t = null; try { Statement s = StatementGenerator.createStatement(req, clientSession.getZoneId()); @@ -405,14 +416,22 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { t = error; throw error; } finally { - COORDINATOR.recordExecutionTime(queryId, System.currentTimeMillis() - startTime); + + long currentOperationCost = System.nanoTime() - startTime; + COORDINATOR.recordExecutionTime(queryId, currentOperationCost); + + // record each operation time cost + addStatementExecutionLatency( + OperationType.EXECUTE_LAST_DATA_QUERY, StatementType.QUERY, currentOperationCost); + if (finished) { - addStatementExecutionLatency( - OperationType.EXECUTE_LAST_DATA_QUERY, - StatementType.QUERY, - COORDINATOR.getTotalExecutionTime(queryId)); + // record total time cost for one query + long executionTime = COORDINATOR.getTotalExecutionTime(queryId); + addQueryLatency( + StatementType.QUERY, executionTime > 0 ? executionTime : currentOperationCost); COORDINATOR.cleanupQueryExecution(queryId, t); } + SESSION_MANAGER.updateIdleTime(); } } @@ -425,7 +444,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { if (!SESSION_MANAGER.checkLogin(clientSession)) { return RpcUtils.getTSExecuteStatementResp(getNotLoggedInStatus()); } - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); Throwable t = null; try { Statement s = StatementGenerator.createStatement(req, clientSession.getZoneId()); @@ -475,14 +494,22 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { t = error; throw error; } finally { - COORDINATOR.recordExecutionTime(queryId, System.currentTimeMillis() - startTime); + + long currentOperationCost = System.nanoTime() - startTime; + COORDINATOR.recordExecutionTime(queryId, currentOperationCost); + + // record each operation time cost + addStatementExecutionLatency( + OperationType.EXECUTE_AGG_QUERY, StatementType.QUERY, currentOperationCost); + if (finished) { - addStatementExecutionLatency( - OperationType.EXECUTE_LAST_DATA_QUERY, - StatementType.QUERY, - COORDINATOR.getTotalExecutionTime(queryId)); + // record total time cost for one query + long executionTime = COORDINATOR.getTotalExecutionTime(queryId); + addQueryLatency( + StatementType.QUERY, executionTime > 0 ? executionTime : currentOperationCost); COORDINATOR.cleanupQueryExecution(queryId, t); } + SESSION_MANAGER.updateIdleTime(); } } @@ -519,7 +546,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSFetchResultsResp fetchResultsV2(TSFetchResultsReq req) { - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); boolean finished = false; StatementType statementType = null; Throwable t = null; @@ -556,19 +583,26 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { t = e; return RpcUtils.getTSFetchResultsResp(onQueryException(e, OperationType.FETCH_RESULTS)); } catch (Error error) { + finished = true; t = error; throw error; } finally { - COORDINATOR.recordExecutionTime(req.queryId, System.currentTimeMillis() - startTime); + + long currentOperationCost = System.nanoTime() - startTime; + COORDINATOR.recordExecutionTime(req.queryId, currentOperationCost); + + // record each operation time cost + addStatementExecutionLatency( + OperationType.FETCH_RESULTS, statementType, currentOperationCost); + if (finished) { - if (statementType != null) { - addStatementExecutionLatency( - OperationType.FETCH_RESULTS, - statementType, - COORDINATOR.getTotalExecutionTime(req.queryId)); - } + // record total time cost for one query + long executionTime = COORDINATOR.getTotalExecutionTime(req.queryId); + addQueryLatency( + StatementType.QUERY, executionTime > 0 ? executionTime : currentOperationCost); COORDINATOR.cleanupQueryExecution(req.queryId, t); } + SESSION_MANAGER.updateIdleTime(); } } @@ -954,7 +988,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus executeBatchStatement(TSExecuteBatchStatementReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); List<TSStatus> results = new ArrayList<>(); boolean isAllSuccessful = true; IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -965,7 +999,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { try { for (int i = 0; i < req.getStatements().size(); i++) { String statement = req.getStatements().get(i); - long t2 = System.currentTimeMillis(); + long t2 = System.nanoTime(); StatementType type = null; try { Statement s = StatementGenerator.createStatement(statement, clientSession.getZoneId()); @@ -1007,14 +1041,12 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { results.add(status); } finally { addStatementExecutionLatency( - OperationType.EXECUTE_STATEMENT, type, System.currentTimeMillis() - t2); + OperationType.EXECUTE_STATEMENT, type, System.nanoTime() - t2); } } } finally { addStatementExecutionLatency( - OperationType.EXECUTE_BATCH_STATEMENT, - StatementType.NULL, - System.currentTimeMillis() - t1); + OperationType.EXECUTE_BATCH_STATEMENT, StatementType.NULL, System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } return isAllSuccessful @@ -1035,7 +1067,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSFetchResultsResp fetchResults(TSFetchResultsReq req) { boolean finished = false; - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); StatementType statementType = null; Throwable t = null; try { @@ -1074,23 +1106,29 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { t = error; throw error; } finally { - COORDINATOR.recordExecutionTime(req.queryId, System.currentTimeMillis() - startTime); + + long currentOperationCost = System.nanoTime() - startTime; + COORDINATOR.recordExecutionTime(req.queryId, currentOperationCost); + + // record each operation time cost + addStatementExecutionLatency( + OperationType.FETCH_RESULTS, statementType, currentOperationCost); + if (finished) { - if (statementType != null) { - addStatementExecutionLatency( - OperationType.FETCH_RESULTS, - statementType, - COORDINATOR.getTotalExecutionTime(req.queryId)); - } + // record total time cost for one query + long executionTime = COORDINATOR.getTotalExecutionTime(req.queryId); + addQueryLatency( + StatementType.QUERY, executionTime > 0 ? executionTime : currentOperationCost); COORDINATOR.cleanupQueryExecution(req.queryId, t); } + SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertRecords(TSInsertRecordsReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1142,16 +1180,14 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { e, OperationType.INSERT_RECORDS, TSStatusCode.EXECUTE_STATEMENT_ERROR); } finally { addStatementExecutionLatency( - OperationType.INSERT_RECORDS, - StatementType.BATCH_INSERT_ROWS, - System.currentTimeMillis() - t1); + OperationType.INSERT_RECORDS, StatementType.BATCH_INSERT_ROWS, System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertRecordsOfOneDevice(TSInsertRecordsOfOneDeviceReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1205,14 +1241,14 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { addStatementExecutionLatency( OperationType.INSERT_RECORDS_OF_ONE_DEVICE, StatementType.BATCH_INSERT_ONE_DEVICE, - System.currentTimeMillis() - t1); + System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertStringRecordsOfOneDevice(TSInsertStringRecordsOfOneDeviceReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1268,14 +1304,14 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { addStatementExecutionLatency( OperationType.INSERT_STRING_RECORDS_OF_ONE_DEVICE, StatementType.BATCH_INSERT_ONE_DEVICE, - System.currentTimeMillis() - t1); + System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertRecord(TSInsertRecordReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1324,14 +1360,14 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { e, OperationType.INSERT_RECORD, TSStatusCode.EXECUTE_STATEMENT_ERROR); } finally { addStatementExecutionLatency( - OperationType.INSERT_RECORD, StatementType.INSERT, System.currentTimeMillis() - t1); + OperationType.INSERT_RECORD, StatementType.INSERT, System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertTablets(TSInsertTabletsReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1373,16 +1409,14 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { e, OperationType.INSERT_TABLETS, TSStatusCode.EXECUTE_STATEMENT_ERROR); } finally { addStatementExecutionLatency( - OperationType.INSERT_TABLETS, - StatementType.MULTI_BATCH_INSERT, - System.currentTimeMillis() - t1); + OperationType.INSERT_TABLETS, StatementType.MULTI_BATCH_INSERT, System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertTablet(TSInsertTabletReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1423,14 +1457,14 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { e, OperationType.INSERT_TABLET, TSStatusCode.EXECUTE_STATEMENT_ERROR); } finally { addStatementExecutionLatency( - OperationType.INSERT_TABLET, StatementType.BATCH_INSERT, System.currentTimeMillis() - t1); + OperationType.INSERT_TABLET, StatementType.BATCH_INSERT, System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @Override public TSStatus insertStringRecords(TSInsertStringRecordsReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -1482,7 +1516,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { addStatementExecutionLatency( OperationType.INSERT_STRING_RECORDS, StatementType.BATCH_INSERT_ROWS, - System.currentTimeMillis() - t1); + System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @@ -1694,7 +1728,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { private TSQueryTemplateResp executeTemplateQueryStatement( Statement statement, TSQueryTemplateReq req, TSQueryTemplateResp resp) { - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); // permission check @@ -1754,9 +1788,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { return null; } finally { addStatementExecutionLatency( - OperationType.EXECUTE_STATEMENT, - statement.getType(), - System.currentTimeMillis() - startTime); + OperationType.EXECUTE_STATEMENT, statement.getType(), System.nanoTime() - startTime); SESSION_MANAGER.updateIdleTime(); } } @@ -1978,7 +2010,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertStringRecord(TSInsertStringRecordReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); if (!SESSION_MANAGER.checkLogin(clientSession)) { @@ -2023,9 +2055,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { e, OperationType.INSERT_STRING_RECORD, TSStatusCode.EXECUTE_STATEMENT_ERROR); } finally { addStatementExecutionLatency( - OperationType.INSERT_STRING_RECORD, - StatementType.INSERT, - System.currentTimeMillis() - t1); + OperationType.INSERT_STRING_RECORD, StatementType.INSERT, System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); } } @@ -2049,6 +2079,24 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { "Log in failed. Either you are not authorized or the session has timed out."); } + /** Add stat of whole stage query into metrics */ + private void addQueryLatency(StatementType statementType, long costTimeInNanos) { + if (statementType == null) { + return; + } + + MetricService.getInstance() + .timer( + costTimeInNanos, + TimeUnit.NANOSECONDS, + Metric.PERFORMANCE_OVERVIEW.toString(), + MetricLevel.CORE, + Tag.INTERFACE.toString(), + OperationType.QUERY_LATENCY.toString(), + Tag.TYPE.toString(), + statementType.name()); + } + /** Add stat of operation into metrics */ private void addStatementExecutionLatency( OperationType operation, StatementType statementType, long costTime) { @@ -2059,7 +2107,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { MetricService.getInstance() .timer( costTime, - TimeUnit.MILLISECONDS, + TimeUnit.NANOSECONDS, Metric.PERFORMANCE_OVERVIEW.toString(), MetricLevel.CORE, Tag.INTERFACE.toString(),
