You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@phoenix.apache.org by ch...@apache.org on 2020/07/15 22:41:28 UTC
[phoenix] branch 4.x updated: PHOENIX-5984: Query timeout counter
is not updated in all timeouts cases
This is an automated email from the ASF dual-hosted git repository.
chinmayskulkarni pushed a commit to branch 4.x
in repository https://gitbox.apache.org/repos/asf/phoenix.git
The following commit(s) were added to refs/heads/4.x by this push:
new db9dcca PHOENIX-5984: Query timeout counter is not updated in all timeouts cases
db9dcca is described below
commit db9dccae63f6008fdb3518de70b4dc00464d20e8
Author: Chinmay Kulkarni <ch...@gmail.com>
AuthorDate: Wed Jul 1 19:57:17 2020 -0700
PHOENIX-5984: Query timeout counter is not updated in all timeouts cases
---
.../monitoring/GlobalPhoenixMetricsTestSink.java | 9 +--
.../phoenix/monitoring/PhoenixMetricsIT.java | 88 +++++++++++++++++-----
.../phoenix/iterate/BaseResultIterators.java | 15 +++-
3 files changed, 82 insertions(+), 30 deletions(-)
diff --git a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/GlobalPhoenixMetricsTestSink.java b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/GlobalPhoenixMetricsTestSink.java
index 10ff2e1..813df6b 100644
--- a/phoenix-core/src/it/java/org/apache/phoenix/monitoring/GlobalPhoenixMetricsTestSink.java
+++ b/phoenix-core/src/it/java/org/apache/phoenix/monitoring/GlobalPhoenixMetricsTestSink.java
@@ -22,13 +22,6 @@ import org.apache.commons.configuration.SubsetConfiguration;
import org.apache.hadoop.metrics2.AbstractMetric;
import org.apache.hadoop.metrics2.MetricsRecord;
import org.apache.hadoop.metrics2.MetricsSink;
-import org.apache.phoenix.util.PhoenixRuntime;
-
-import java.util.Map;
-
-import static junit.framework.TestCase.assertTrue;
-import static org.junit.Assert.assertEquals;
-import static org.junit.Assert.fail;
public class GlobalPhoenixMetricsTestSink implements MetricsSink {
@@ -36,7 +29,7 @@ public class GlobalPhoenixMetricsTestSink implements MetricsSink {
// PhoenixMetricsIT tests verifies these metrics from this sink in a separate thread
// GlobalPhoenixMetricsTestSink is invoked based on time defined in hadoop-metrics2.properties
// This lock is to prevent concurrent access to metrics Iterable for these threads
- static Object lock = new Object();
+ static final Object lock = new Object();
static Iterable<AbstractMetric> metrics;
@Override
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 946a929..e8d9e40 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
@@ -9,6 +9,7 @@
*/
package org.apache.phoenix.monitoring;
+import static org.apache.phoenix.exception.SQLExceptionCode.OPERATION_TIMED_OUT;
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_FAILED_QUERY_COUNTER;
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_HBASE_COUNT_BYTES_REGION_SERVER_RESULTS;
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_HBASE_COUNT_MILLS_BETWEEN_NEXTS;
@@ -35,6 +36,7 @@ import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_SPOOL_FIL
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_TASK_END_TO_END_TIME;
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_TASK_EXECUTION_TIME;
import static org.apache.phoenix.monitoring.MetricType.MEMORY_CHUNK_BYTES;
+import static org.apache.phoenix.monitoring.MetricType.QUERY_TIMEOUT_COUNTER;
import static org.apache.phoenix.monitoring.MetricType.TASK_EXECUTED_COUNTER;
import static org.apache.phoenix.monitoring.MetricType.TASK_EXECUTION_TIME;
import static org.apache.phoenix.util.PhoenixRuntime.TENANT_ID_ATTRIB;
@@ -71,6 +73,8 @@ import org.apache.phoenix.jdbc.PhoenixDriver;
import org.apache.phoenix.jdbc.PhoenixResultSet;
import org.apache.phoenix.log.LogLevel;
import org.apache.phoenix.query.QueryServices;
+import org.apache.phoenix.util.EnvironmentEdge;
+import org.apache.phoenix.util.EnvironmentEdgeManager;
import org.apache.phoenix.util.PhoenixRuntime;
import org.hamcrest.CoreMatchers;
import org.junit.Test;
@@ -93,6 +97,23 @@ public class PhoenixMetricsIT extends BasePhoenixMetricsIT {
private static final Logger LOGGER = LoggerFactory.getLogger(PhoenixMetricsIT.class);
+ private static class MyClock extends EnvironmentEdge {
+ private long time;
+ private final long delay;
+
+ public MyClock (long time, long delay) {
+ this.time = time;
+ this.delay = delay;
+ }
+
+ @Override
+ public long currentTime() {
+ long currentTime = this.time;
+ this.time += this.delay;
+ return currentTime;
+ }
+ }
+
@Test
public void testResetGlobalPhoenixMetrics() throws Exception {
resetGlobalMetrics();
@@ -249,28 +270,32 @@ public class PhoenixMetricsIT extends BasePhoenixMetricsIT {
}
}
}
- assertTrue("Metric expected but not present in Hadoop Metrics Sink (GlobalPhoenixMetricsTestSink)",
- expectedMetrics.size() == 0);
+ assertEquals("Metric expected but not present in Hadoop Metrics Sink "
+ + "(GlobalPhoenixMetricsTestSink)", 0, expectedMetrics.size());
return true;
}
- private static void createTableAndInsertValues(String tableName, boolean resetGlobalMetricsAfterTableCreate)
- throws Exception {
- String ddl = "CREATE TABLE " + tableName + " (K VARCHAR NOT NULL PRIMARY KEY, V VARCHAR)";
- Connection conn = DriverManager.getConnection(getUrl());
- conn.createStatement().execute(ddl);
- if (resetGlobalMetricsAfterTableCreate) {
- resetGlobalMetrics();
- }
- // executing 10 upserts/mutations.
- String dml = "UPSERT INTO " + tableName + " VALUES (?, ?)";
- PreparedStatement stmt = conn.prepareStatement(dml);
- for (int i = 1; i <= 10; i++) {
- stmt.setString(1, "key" + i);
- stmt.setString(2, "value" + i);
- stmt.executeUpdate();
+ private static void createTableAndInsertValues(String tableName,
+ boolean resetGlobalMetricsAfterTableCreate) throws SQLException {
+ String ddl = String.format("CREATE TABLE %s (K VARCHAR NOT NULL PRIMARY KEY, V VARCHAR)",
+ tableName);
+ try (Connection conn = DriverManager.getConnection(getUrl());
+ Statement stmt = conn.createStatement()) {
+ stmt.execute(ddl);
+ if (resetGlobalMetricsAfterTableCreate) {
+ resetGlobalMetrics();
+ }
+ // executing 10 upserts/mutations.
+ String dml = String.format("UPSERT INTO %s VALUES (?, ?)", tableName);
+ try(PreparedStatement prepStmt = conn.prepareStatement(dml)) {
+ for (int i = 1; i <= 10; i++) {
+ prepStmt.setString(1, "key" + i);
+ prepStmt.setString(2, "value" + i);
+ prepStmt.executeUpdate();
+ }
+ }
+ conn.commit();
}
- conn.commit();
}
@Test
@@ -298,6 +323,33 @@ public class PhoenixMetricsIT extends BasePhoenixMetricsIT {
}
@Test
+ public void testMetricsForSelectFetchResultsTimeout() throws SQLException {
+ String tableName = generateUniqueName();
+ final int queryTimeout = 10; //seconds
+ createTableAndInsertValues(tableName, true);
+ try (Connection conn = DriverManager.getConnection(getUrl());
+ Statement stmt = conn.createStatement()) {
+ stmt.setQueryTimeout(queryTimeout);
+ ResultSet rs = stmt.executeQuery(String.format("SELECT * FROM %s", tableName));
+ // Make the query time out with a longer delay than the set query timeout value (in ms)
+ MyClock clock = new MyClock(10, queryTimeout * 2 * 1000);
+ EnvironmentEdgeManager.injectEdge(clock);
+ try {
+ rs.next();
+ fail();
+ } catch (SQLException e) {
+ assertEquals(OPERATION_TIMED_OUT.getErrorCode(), e.getErrorCode());
+ }
+ Map<MetricType, Long> overallReadMetrics =
+ PhoenixRuntime.getOverAllReadRequestMetricInfo(rs);
+ assertEquals(1L, (long)overallReadMetrics.get(QUERY_TIMEOUT_COUNTER));
+ assertEquals(1L, GLOBAL_QUERY_TIMEOUT_COUNTER.getMetric().getValue());
+ } finally {
+ EnvironmentEdgeManager.reset();
+ }
+ }
+
+ @Test
public void testReadMetricsForSelect() throws Exception {
String tableName = generateUniqueName();
long numSaltBuckets = 6;
diff --git a/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java b/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
index c54a472..c271487 100644
--- a/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
+++ b/phoenix-core/src/main/java/org/apache/phoenix/iterate/BaseResultIterators.java
@@ -21,6 +21,7 @@ import static org.apache.phoenix.coprocessor.BaseScannerRegionObserver.LOCAL_IND
import static org.apache.phoenix.coprocessor.BaseScannerRegionObserver.SCAN_ACTUAL_START_ROW;
import static org.apache.phoenix.coprocessor.BaseScannerRegionObserver.SCAN_START_ROW_SUFFIX;
import static org.apache.phoenix.coprocessor.BaseScannerRegionObserver.SCAN_STOP_ROW_SUFFIX;
+import static org.apache.phoenix.exception.SQLExceptionCode.OPERATION_TIMED_OUT;
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_FAILED_QUERY_COUNTER;
import static org.apache.phoenix.monitoring.GlobalClientMetrics.GLOBAL_QUERY_TIMEOUT_COUNTER;
import static org.apache.phoenix.query.QueryServices.WILDCARD_QUERY_DYNAMIC_COLS_ATTRIB;
@@ -1317,7 +1318,9 @@ public abstract class BaseResultIterators extends ExplainTable implements Result
try {
long timeOutForScan = maxQueryEndTime - EnvironmentEdgeManager.currentTimeMillis();
if (timeOutForScan < 0) {
- throw new SQLExceptionInfo.Builder(SQLExceptionCode.OPERATION_TIMED_OUT).setMessage(". Query couldn't be completed in the alloted time: " + queryTimeOut + " ms").build().buildException();
+ throw new SQLExceptionInfo.Builder(OPERATION_TIMED_OUT).setMessage(
+ ". Query couldn't be completed in the allotted time: "
+ + queryTimeOut + " ms").build().buildException();
}
// make sure we apply the iterators in order
if (isLocalIndex && previousScan != null && previousScan.getScan() != null
@@ -1382,10 +1385,14 @@ public abstract class BaseResultIterators extends ExplainTable implements Result
context.getOverallQueryMetrics().queryTimedOut();
GLOBAL_QUERY_TIMEOUT_COUNTER.increment();
// thrown when a thread times out waiting for the future.get() call to return
- toThrow = new SQLExceptionInfo.Builder(SQLExceptionCode.OPERATION_TIMED_OUT)
- .setMessage(". Query couldn't be completed in the alloted time: " + queryTimeOut + " ms")
- .setRootCause(e).build().buildException();
+ toThrow = new SQLExceptionInfo.Builder(OPERATION_TIMED_OUT)
+ .setMessage(". Query couldn't be completed in the allotted time: "
+ + queryTimeOut + " ms").setRootCause(e).build().buildException();
} catch (SQLException e) {
+ if (e.getErrorCode() == OPERATION_TIMED_OUT.getErrorCode()) {
+ context.getOverallQueryMetrics().queryTimedOut();
+ GLOBAL_QUERY_TIMEOUT_COUNTER.increment();
+ }
toThrow = e;
} catch (Exception e) {
toThrow = ServerUtil.parseServerException(e);