This is an automated email from the ASF dual-hosted git repository. jackietien pushed a commit to branch QueryMetricOpt in repository https://gitbox.apache.org/repos/asf/iotdb.git
commit 313f725ccc2240b1a59f37a94d38d54855b08416 Author: JackieTien97 <[email protected]> AuthorDate: Fri May 19 16:43:51 2023 +0800 Change cost time unit from milli to nano --- .../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 +- .../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 +++++++++++++-------- 9 files changed, 135 insertions(+), 92 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/metric/TimeSeriesMetadataCacheMetrics.java b/server/src/main/java/org/apache/iotdb/db/mpp/metric/TimeSeriesMetadataCacheMetrics.java index 07d9b7f57bb..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 -> (long) 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 e6bcdeb728b..abbc3a7c339 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 @@ -137,7 +137,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 5d1456935b3..c5e26996703 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 @@ -197,7 +197,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 { @@ -264,15 +264,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(); @@ -291,7 +295,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()); @@ -349,14 +353,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(); if (quota != null) { quota.close(); @@ -373,7 +384,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()); @@ -431,14 +442,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(); if (quota != null) { quota.close(); @@ -455,7 +474,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()); @@ -510,14 +529,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(); if (quota != null) { quota.close(); @@ -557,7 +584,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; @@ -594,19 +621,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(); } } @@ -993,7 +1027,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(); @@ -1004,7 +1038,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; OperationQuota quota = null; try { @@ -1051,7 +1085,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { results.add(status); } finally { addStatementExecutionLatency( - OperationType.EXECUTE_STATEMENT, type, System.currentTimeMillis() - t2); + OperationType.EXECUTE_STATEMENT, type, System.nanoTime() - t2); if (quota != null) { quota.close(); } @@ -1059,9 +1093,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { } } 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 @@ -1082,7 +1114,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 { @@ -1121,23 +1153,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(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1194,9 +1232,7 @@ 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(); if (quota != null) { quota.close(); @@ -1206,7 +1242,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertRecordsOfOneDevice(TSInsertRecordsOfOneDeviceReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1265,7 +1301,7 @@ 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(); if (quota != null) { quota.close(); @@ -1275,7 +1311,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertStringRecordsOfOneDevice(TSInsertStringRecordsOfOneDeviceReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1336,7 +1372,7 @@ 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(); if (quota != null) { quota.close(); @@ -1346,7 +1382,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertRecord(TSInsertRecordReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1400,7 +1436,7 @@ 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(); if (quota != null) { quota.close(); @@ -1410,7 +1446,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertTablets(TSInsertTabletsReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1457,9 +1493,7 @@ 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(); if (quota != null) { quota.close(); @@ -1469,7 +1503,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertTablet(TSInsertTabletReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1515,7 +1549,7 @@ 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(); if (quota != null) { quota.close(); @@ -1525,7 +1559,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertStringRecords(TSInsertStringRecordsReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1582,7 +1616,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { addStatementExecutionLatency( OperationType.INSERT_STRING_RECORDS, StatementType.BATCH_INSERT_ROWS, - System.currentTimeMillis() - t1); + System.nanoTime() - t1); SESSION_MANAGER.updateIdleTime(); if (quota != null) { quota.close(); @@ -1797,7 +1831,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { private TSQueryTemplateResp executeTemplateQueryStatement( Statement statement, TSQueryTemplateReq req, TSQueryTemplateResp resp) { - long startTime = System.currentTimeMillis(); + long startTime = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -1862,9 +1896,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(); } } @@ -2086,7 +2118,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { @Override public TSStatus insertStringRecord(TSInsertStringRecordReq req) { - long t1 = System.currentTimeMillis(); + long t1 = System.nanoTime(); OperationQuota quota = null; try { IClientSession clientSession = SESSION_MANAGER.getCurrSessionAndUpdateIdleTime(); @@ -2136,9 +2168,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(); if (quota != null) { quota.close(); @@ -2165,6 +2195,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) { @@ -2175,7 +2223,7 @@ public class ClientRPCServiceImpl implements IClientRPCServiceWithHandler { MetricService.getInstance() .timer( costTime, - TimeUnit.MILLISECONDS, + TimeUnit.NANOSECONDS, Metric.PERFORMANCE_OVERVIEW.toString(), MetricLevel.CORE, Tag.INTERFACE.toString(),
