You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by mm...@apache.org on 2020/12/29 09:34:16 UTC
[ignite] branch master updated: IGNITE-13456 Extends info collected
during tracing of SQL queries. (#8393)
This is an automated email from the ASF dual-hosted git repository.
mmuzaf pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/ignite.git
The following commit(s) were added to refs/heads/master by this push:
new f17a4cb IGNITE-13456 Extends info collected during tracing of SQL queries. (#8393)
f17a4cb is described below
commit f17a4cbb16d134ed207a750949b3cd981b55becd
Author: Mikhail Petrov <32...@users.noreply.github.com>
AuthorDate: Tue Dec 29 12:34:01 2020 +0300
IGNITE-13456 Extends info collected during tracing of SQL queries. (#8393)
---
.../dht/topology/GridDhtPartitionsReservation.java | 9 ++
.../internal/processors/tracing/SpanTags.java | 3 +
.../internal/processors/query/h2/QueryParser.java | 5 ++
.../h2/twostep/PartitionReservationManager.java | 10 +++
.../monitoring/opencensus/AbstractTracingTest.java | 6 ++
.../opencensus/OpenCensusSqlJdbcTracingTest.java | 2 +-
.../opencensus/OpenCensusSqlNativeTracingTest.java | 95 +++++++++++++++++-----
7 files changed, 109 insertions(+), 21 deletions(-)
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/topology/GridDhtPartitionsReservation.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/topology/GridDhtPartitionsReservation.java
index 8e975f8..d522eb4 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/topology/GridDhtPartitionsReservation.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/topology/GridDhtPartitionsReservation.java
@@ -26,6 +26,7 @@ import org.apache.ignite.internal.processors.cache.GridCacheContext;
import org.apache.ignite.internal.processors.cache.distributed.dht.GridReservable;
import org.apache.ignite.internal.util.typedef.CI1;
import org.apache.ignite.internal.util.typedef.F;
+import org.apache.ignite.internal.util.typedef.internal.S;
/**
* Reservation mechanism for multiple partitions allowing to do a reservation in one operation.
@@ -281,4 +282,12 @@ public class GridDhtPartitionsReservation implements GridReservable {
return result;
}
+
+ /** {@inheritDoc} */
+ @Override public String toString() {
+ return S.toString(null,
+ "cache", cctx.name(), false,
+ "partitions", Arrays.toString(parts.get()), false,
+ "topology", topVer.toString(), false);
+ }
}
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/tracing/SpanTags.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/tracing/SpanTags.java
index 75c3a23..c2f37a6 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/tracing/SpanTags.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/tracing/SpanTags.java
@@ -105,6 +105,9 @@ public class SpanTags {
/** Number of cache entries to be updated as a result of DML query. */
public static final String SQL_CACHE_UPDATES = "sql.cache.updates";
+ /** Whether parsing of the SQL query was skipped due to the cached result. */
+ public static final String SQL_PARSER_CACHE_HIT = "sql.parser.cache.hit";
+
/** */
private SpanTags() {}
diff --git a/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/QueryParser.java b/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/QueryParser.java
index 751cb80..b1e5bd1 100644
--- a/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/QueryParser.java
+++ b/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/QueryParser.java
@@ -84,6 +84,7 @@ import org.h2.command.Prepared;
import org.jetbrains.annotations.Nullable;
import static org.apache.ignite.internal.processors.query.h2.sql.GridSqlQuerySplitter.keyColumn;
+import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_PARSER_CACHE_HIT;
import static org.apache.ignite.internal.processors.tracing.SpanType.SQL_QRY_PARSE;
/**
@@ -204,6 +205,8 @@ public class QueryParser {
if (cached != null) {
metricsHolder.countCacheHit();
+ MTC.span().addTag(SQL_PARSER_CACHE_HIT, () -> "true");
+
return new QueryParserResult(
qryDesc,
queryParameters(qry),
@@ -217,6 +220,8 @@ public class QueryParser {
metricsHolder.countCacheMiss();
+ MTC.span().addTag(SQL_PARSER_CACHE_HIT, () -> "false");
+
// Try parsing as native command.
QueryParserResult parseRes = parseNative(schemaName, qry, remainingAllowed);
diff --git a/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/twostep/PartitionReservationManager.java b/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/twostep/PartitionReservationManager.java
index d7c9dba..4c7f351 100644
--- a/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/twostep/PartitionReservationManager.java
+++ b/modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/twostep/PartitionReservationManager.java
@@ -158,6 +158,8 @@ public class PartitionReservationManager implements PartitionsExchangeAware {
"cacheName=%s]", ctx.localNodeId(), nodeId, reqId, topVer, cacheIds.get(i), cctx.name()));
reserved.add(r);
+
+ MTC.span().addLog(() -> "Cache partitions were reserved " + r);
}
}
else { // Try to reserve partitions one by one.
@@ -191,6 +193,9 @@ public class PartitionReservationManager implements PartitionsExchangeAware {
// Mark that we checked this replicated cache.
reservations.putIfAbsent(grpKey, REPLICATED_RESERVABLE);
+
+ MTC.span().addLog(() -> "Cache partitions were reserved [cache=" + cctx.name() +
+ ", partitions=[0.." + partsCnt + ']');
}
}
else { // Reserve primary partitions for partitioned cache (if no explicit given).
@@ -273,6 +278,11 @@ public class PartitionReservationManager implements PartitionsExchangeAware {
}
}
+ final Collection<Integer> finalPartIds = partIds;
+
+ MTC.span().addLog(() -> "Cache partitions were reserved [cache=" + cctx.name() +
+ ", partitions=" + finalPartIds + ", topology=" + topVer + ']');
+
if (explicitParts == null && reservedCnt > 0) {
// We reserved all the primary partitions for cache, attempt to add group reservation.
GridDhtPartitionsReservation grp = new GridDhtPartitionsReservation(topVer, cctx, "SQL");
diff --git a/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/AbstractTracingTest.java b/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/AbstractTracingTest.java
index 007e821..450ed81 100644
--- a/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/AbstractTracingTest.java
+++ b/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/AbstractTracingTest.java
@@ -402,5 +402,11 @@ public abstract class AbstractTracingTest extends GridCommonAbstractTest {
span.end();
}
}
+
+ /** Clears collected spans. */
+ void clearCollectedSpans() {
+ collectedSpans.clear();
+ collectedSpansByParents.clear();
+ }
}
}
diff --git a/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlJdbcTracingTest.java b/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlJdbcTracingTest.java
index fe9aa1a..a324ada 100644
--- a/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlJdbcTracingTest.java
+++ b/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlJdbcTracingTest.java
@@ -81,7 +81,7 @@ public class OpenCensusSqlJdbcTracingTest extends OpenCensusSqlNativeTracingTest
checkChildSpan(SQL_QRY_EXECUTE, iterSpan);
int fetchedRows = findChildSpans(SQL_PAGE_FETCH, rootSpan).stream()
- .mapToInt(span -> getAttribute(span, SQL_PAGE_ROWS))
+ .mapToInt(span -> Integer.parseInt(getAttribute(span, SQL_PAGE_ROWS)))
.sum();
assertEquals(TEST_TABLE_POPULATION, fetchedRows);
diff --git a/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlNativeTracingTest.java b/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlNativeTracingTest.java
index d48f91c..9698329 100644
--- a/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlNativeTracingTest.java
+++ b/modules/opencensus/src/test/java/org/apache/ignite/internal/processors/monitoring/opencensus/OpenCensusSqlNativeTracingTest.java
@@ -17,14 +17,21 @@
package org.apache.ignite.internal.processors.monitoring.opencensus;
+import java.util.Arrays;
import java.util.List;
+import java.util.Set;
+import java.util.UUID;
import java.util.concurrent.atomic.AtomicInteger;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
import java.util.stream.Collectors;
import com.google.common.collect.ImmutableMap;
import io.opencensus.trace.SpanId;
import io.opencensus.trace.Tracing;
+import org.apache.ignite.Ignite;
import org.apache.ignite.IgniteCache;
import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.Ignition;
import org.apache.ignite.cache.CacheMode;
import org.apache.ignite.cache.query.SqlFieldsQuery;
import org.apache.ignite.cache.query.annotations.QuerySqlField;
@@ -44,7 +51,9 @@ import org.apache.ignite.spi.tracing.opencensus.OpenCensusTracingSpi;
import org.apache.ignite.testframework.GridTestUtils;
import org.junit.Test;
+import static java.lang.Boolean.parseBoolean;
import static java.lang.Integer.parseInt;
+import static java.util.regex.Pattern.compile;
import static org.apache.ignite.cache.CacheMode.PARTITIONED;
import static org.apache.ignite.internal.TestRecordingCommunicationSpi.spi;
import static org.apache.ignite.internal.processors.query.QueryUtils.DFLT_SCHEMA;
@@ -55,6 +64,7 @@ import static org.apache.ignite.internal.processors.tracing.SpanTags.NODE_ID;
import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_CACHE_UPDATES;
import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_IDX_RANGE_ROWS;
import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_PAGE_ROWS;
+import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_PARSER_CACHE_HIT;
import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_QRY_TEXT;
import static org.apache.ignite.internal.processors.tracing.SpanTags.SQL_SCHEMA;
import static org.apache.ignite.internal.processors.tracing.SpanTags.tag;
@@ -160,13 +170,13 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
checkChildSpan(SQL_QRY_EXECUTE, iterSpan);
fetchedRows += findChildSpans(SQL_PAGE_FETCH, execReqSpan).stream()
- .mapToInt(span -> getAttribute(span, SQL_PAGE_ROWS))
+ .mapToInt(span -> parseInt(getAttribute(span, SQL_PAGE_ROWS)))
.sum();
List<SpanId> cacheUpdateSpans = findChildSpans(SQL_CACHE_UPDATE, execReqSpan);
cacheUpdates += cacheUpdateSpans.stream()
- .mapToInt(span -> getAttribute(span, SQL_CACHE_UPDATES))
+ .mapToInt(span -> parseInt(getAttribute(span, SQL_CACHE_UPDATES)))
.sum();
checkChildSpan(SQL_ITER_CLOSE, execReqSpan);
@@ -287,41 +297,65 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
for (int i = 0; i < GRID_CNT; i++) {
SpanId execReqSpan = execReqSpans.get(i);
- checkChildSpan(SQL_PARTITIONS_RESERVE, execReqSpan);
+ Ignite ignite = Ignition.ignite(UUID.fromString(getAttribute(execReqSpan, NODE_ID)));
+
+ SpanId partsReserveSpan = checkChildSpan(SQL_PARTITIONS_RESERVE, execReqSpan);
+
+ List<String> partsReserveLogs = handler().spanById(partsReserveSpan).getAnnotations().getEvents().stream()
+ .map(e -> e.getEvent().getDescription())
+ .collect(Collectors.toList());
+
+ assertEquals(2, partsReserveLogs.size());
+
+ Pattern ptrn = compile("Cache partitions were reserved \\[cache=(.+), partitions=\\[(.+)], topology=(.+)]");
+
+ partsReserveLogs.forEach(l -> {
+ Matcher matcher = ptrn.matcher(l);
+
+ assertTrue(matcher.matches());
+
+ Set<Integer> expParts = Arrays.stream(ignite.affinity(matcher.group(1))
+ .primaryPartitions(ignite.cluster().localNode())
+ ).boxed().collect(Collectors.toSet());
+
+ Set<Integer> parts = Arrays.stream(matcher.group(2).split(","))
+ .map(s -> Integer.parseInt(s.trim()))
+ .collect(Collectors.toSet());
+
+ assertEquals(expParts, parts);
+ });
SpanId execSpan = checkChildSpan(SQL_QRY_EXECUTE, execReqSpan);
List<SpanId> distrLookupReqSpans = findChildSpans(SQL_IDX_RANGE_REQ, execSpan);
for (SpanId span : distrLookupReqSpans) {
- idxRangeReqRows += getAttribute(span, SQL_IDX_RANGE_ROWS);
+ idxRangeReqRows += parseInt(getAttribute(span, SQL_IDX_RANGE_ROWS));
checkChildSpan(SQL_IDX_RANGE_RESP, span);
}
- preparedRows += getAttribute(
- checkChildSpan(SQL_PAGE_PREPARE, execReqSpan), SQL_PAGE_ROWS);
+ preparedRows += parseInt(getAttribute(checkChildSpan(SQL_PAGE_PREPARE, execReqSpan), SQL_PAGE_ROWS));
checkChildSpan(SQL_PAGE_RESP, execReqSpan);
}
SpanId pageFetchSpan = checkChildSpan(SQL_PAGE_FETCH, iterSpan);
- fetchedRows += getAttribute(pageFetchSpan, SQL_PAGE_ROWS);
+ fetchedRows += parseInt(getAttribute(pageFetchSpan, SQL_PAGE_ROWS));
checkChildSpan(SQL_PAGE_WAIT, pageFetchSpan);
SpanId nexPageSpan = checkChildSpan(SQL_NEXT_PAGE_REQ, pageFetchSpan);
- preparedRows += getAttribute(
- checkChildSpan(SQL_PAGE_PREPARE, nexPageSpan), SQL_PAGE_ROWS);
+ preparedRows += parseInt(getAttribute(checkChildSpan(SQL_PAGE_PREPARE, nexPageSpan), SQL_PAGE_ROWS));
checkChildSpan(SQL_PAGE_RESP, nexPageSpan);
List<SpanId> pageFetchSpans = findChildSpans(SQL_PAGE_FETCH, rootSpan);
for (SpanId span : pageFetchSpans) {
- fetchedRows += getAttribute(span, SQL_PAGE_ROWS);
+ fetchedRows += parseInt(getAttribute(span, SQL_PAGE_ROWS));
checkChildSpan(SQL_PAGE_WAIT, span);
@@ -332,8 +366,7 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
SpanId nextPageSpan = nextPageSpans.get(0);
- preparedRows += getAttribute(
- checkChildSpan(SQL_PAGE_PREPARE, nextPageSpan), SQL_PAGE_ROWS);
+ preparedRows += parseInt(getAttribute(checkChildSpan(SQL_PAGE_PREPARE, nextPageSpan), SQL_PAGE_ROWS));
checkChildSpan(SQL_PAGE_RESP, nextPageSpan);
}
@@ -364,9 +397,9 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
SpanId iterOpenSpan = checkChildSpan(SQL_ITER_OPEN, rootSpan);
- List<SpanId> qryExecspans = findChildSpans(SQL_QRY_EXEC_REQ, iterOpenSpan);
+ List<SpanId> qryExecSpans = findChildSpans(SQL_QRY_EXEC_REQ, iterOpenSpan);
- assertEquals(GRID_CNT * qryParallelism, qryExecspans.size());
+ assertEquals(GRID_CNT * qryParallelism, qryExecSpans.size());
}
/**
@@ -433,6 +466,28 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
checkChildSpan(SQL_CMD_QRY_EXECUTE, rootSpan);
}
+ /** Tests SQL parser cache hit tag. */
+ @Test
+ public void testParserCacheHitTag() throws Exception {
+ String prsnTable = createTableAndPopulate(Person.class, PARTITIONED, 1);
+
+ SpanId rootSpan = executeAndCheckRootSpan("SELECT * FROM " + prsnTable,
+ TEST_SCHEMA, false, false, true);
+
+ SpanId qryParseSpan = checkChildSpan(SQL_QRY_PARSE, rootSpan);
+
+ assertFalse(parseBoolean(getAttribute(qryParseSpan, SQL_PARSER_CACHE_HIT)));
+
+ handler().clearCollectedSpans();
+
+ rootSpan = executeAndCheckRootSpan("SELECT * FROM " + prsnTable,
+ TEST_SCHEMA, false, false, true);
+
+ qryParseSpan = checkChildSpan(SQL_QRY_PARSE, rootSpan);
+
+ assertTrue(parseBoolean(getAttribute(qryParseSpan, SQL_PARSER_CACHE_HIT)));
+ }
+
/**
* Executes DML query and checks corresponding span tree.
*
@@ -450,14 +505,14 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
checkChildSpan(SQL_ITER_OPEN, dmlExecSpan);
int fetchedRows = findChildSpans(SQL_PAGE_FETCH, null).stream()
- .mapToInt(span -> getAttribute(span, SQL_PAGE_ROWS))
+ .mapToInt(span -> parseInt(getAttribute(span, SQL_PAGE_ROWS)))
.sum();
assertEquals(expCacheUpdates, fetchedRows);
}
int cacheUpdates = findChildSpans(SQL_CACHE_UPDATE, dmlExecSpan).stream()
- .mapToInt(span -> getAttribute(span, SQL_CACHE_UPDATES))
+ .mapToInt(span -> parseInt(getAttribute(span, SQL_CACHE_UPDATES)))
.sum();
assertEquals(expCacheUpdates, cacheUpdates);
@@ -491,18 +546,18 @@ public class OpenCensusSqlNativeTracingTest extends AbstractTracingTest {
}
/**
- * Obtains integer value of the attribtute from span with specified id.
+ * Obtains string representation of the attribtute from span with specified id.
*
* @param spanId Id of the target span.
* @param tag Tag of the attribute.
* @return Value of the attribute.
*/
- protected int getAttribute(SpanId spanId, String tag) {
- return parseInt(attributeValueToString(handler()
+ protected String getAttribute(SpanId spanId, String tag) {
+ return attributeValueToString(handler()
.spanById(spanId)
.getAttributes()
.getAttributeMap()
- .get(tag)));
+ .get(tag));
}
/**