IGNITE-24385 Fixed performance drop introduced by SQL plan history system view - Fixes #11848.

Signed-off-by: Aleksey Plekhanov <plehanov.alex@gmail.com>

Author: oleg-vlsk

modules/calcite/src/main/java/org/apache/ignite/internal/processors/query/calcite/exec/ExecutionServiceImpl.java

@@ -710,13 +710,15 @@ private ListFieldsQueryCursor<?> mapAndExecutePlan(
             );
         }
 
-        ctx.query().runningQueryManager().planHistoryTracker().addPlan(
-            plan.textPlan(),
-            qry.sql(),
-            qry.context().schemaName(),
-            qry.context().isLocal(),
-            CalciteQueryEngineConfiguration.ENGINE_NAME
-        );
+        if (ctx.query().runningQueryManager().planHistoryTracker().enabled()) {
+            ctx.query().runningQueryManager().planHistoryTracker().addPlan(
+                plan.textPlan(),
+                qry.sql(),
+                qry.context().schemaName(),
+                qry.context().isLocal(),
+                CalciteQueryEngineConfiguration.ENGINE_NAME
+            );
+        }
 
         QueryProperties qryProps = qry.context().unwrap(QueryProperties.class);
 

modules/calcite/src/test/java/org/apache/ignite/internal/processors/query/calcite/integration/SqlPlanHistoryIntegrationTest.java

@@ -269,15 +269,17 @@ public void testSqlFieldsCrossCacheQueryFailed() throws Exception {
      */
     @Test
     public void testSqlFieldsQueryWithReducePhase() throws Exception {
-        runQueryWithReducePhase(() -> {
-            try {
-                startGridsMultiThreaded(1, 2);
+        assumeTrue("Map/reduce queries are only applicable to H2 engine",
+            sqlEngine == IndexingQueryEngineConfiguration.ENGINE_NAME);
 
-                awaitPartitionMapExchange();
-            }
-            catch (Exception e) {
-                throw new RuntimeException(e);
-            }
+        assumeFalse("Only distributed queries have map and reduce phases", loc);
+
+        startTestGrid();
+
+        try {
+            startGridsMultiThreaded(1, 2);
+
+            awaitPartitionMapExchange();
 
             cacheQuery(new SqlFieldsQuery(SQL_WITH_REDUCE_PHASE).setDistributedJoins(true), "pers");
 
@@ -286,11 +288,14 @@ public void testSqlFieldsQueryWithReducePhase() throws Exception {
             for (int i = 1; i <= 2; i++) {
                 List<SqlPlanHistoryView> sqlPlansOnMapNode = getSqlPlanHistory(grid(i));
 
-                assertNotNull(sqlPlansOnMapNode);
+                assertTrue(waitForCondition(() -> sqlPlansOnMapNode.size() == 2, 1000));
 
-                checkMetrics(2, sqlPlansOnMapNode);
+                checkMetrics(sqlPlansOnMapNode);
             }
-        });
+        }
+        catch (Exception e) {
+            throw new RuntimeException(e);
+        }
     }
 
     /** Checks successful SqlQuery. */
@@ -356,7 +361,8 @@ public void testPlanHistoryEviction() throws Exception {
             cacheQuery(qry, "A");
         }
 
-        assertTrue(waitForCondition(() -> getSqlPlanHistory().size() == planHistorySize, 1000));
+        assertTrue(waitForCondition(() -> getSqlPlanHistory().stream().map(SqlPlanHistoryView::sql).anyMatch(str ->
+            str.contains("STR" + String.format("%02d", planHistorySize + PLAN_HISTORY_EXCESS))), 1000));
 
         Set<String> qrys = getSqlPlanHistory().stream().map(SqlPlanHistoryView::sql).collect(Collectors.toSet());
 
@@ -377,23 +383,21 @@ public void testPlanHistoryEviction() throws Exception {
     public void testEntryReplacement() throws Exception {
         startTestGrid();
 
-        long[] timeStamps = new long[2];
+        long firstTs;
 
-        for (int i = 0; i < 2; i++) {
-            cacheQuery(new SqlFieldsQuery(SQL), "A");
+        cacheQuery(new SqlFieldsQuery(SQL), "A");
 
-            checkSqlPlanHistory(1);
+        assertTrue(waitForCondition(() -> !getSqlPlanHistory().isEmpty(), 1000));
 
-            timeStamps[i] = F.first(getSqlPlanHistory()).lastStartTime().getTime();
+        firstTs = F.first(getSqlPlanHistory()).lastStartTime().getTime();
 
-            if (i == 0) {
-                long ts0 = U.currentTimeMillis();
+        long curTs = U.currentTimeMillis();
 
-                assertTrue(waitForCondition(() -> (U.currentTimeMillis() != ts0), 1000));
-            }
-        }
+        assertTrue(waitForCondition(() -> (U.currentTimeMillis() != curTs), 1000));
 
-        assertTrue(timeStamps[1] > timeStamps[0]);
+        cacheQuery(new SqlFieldsQuery(SQL), "A");
+
+        assertTrue(waitForCondition(() -> F.first(getSqlPlanHistory()).lastStartTime().getTime() > firstTs, 1000));
     }
 
     /** Checks that SQL plan history stays empty if the grid is started with a zero history size. */
@@ -489,21 +493,7 @@ public void runQueryWithoutPlan(Query qry) throws Exception {
 
         cacheQuery(qry, "A");
 
-        checkSqlPlanHistory(0);
-    }
-
-    /**
-     * @param task Test task to execute.
-     */
-    public void runQueryWithReducePhase(Runnable task) throws Exception {
-        assumeTrue("Map/reduce queries are only applicable to H2 engine",
-            sqlEngine == IndexingQueryEngineConfiguration.ENGINE_NAME);
-
-        assumeFalse("Only distributed queries have map and reduce phases", loc);
-
-        startTestGrid();
-
-        task.run();
+        assertTrue(getSqlPlanHistory().isEmpty());
     }
 
     /**
@@ -619,12 +609,10 @@ public List<SqlPlanHistoryView> getSqlPlanHistory(IgniteEx node) {
      *
      * @param size Number of SQL plan entries expected to be in the history.
      */
-    public void checkSqlPlanHistory(int size) {
-        List<SqlPlanHistoryView> sqlPlans = getSqlPlanHistory();
-
-        assertNotNull(sqlPlans);
+    public void checkSqlPlanHistory(int size) throws Exception {
+        assertTrue(waitForCondition(() -> getSqlPlanHistory().size() == size, 1000));
 
-        checkMetrics(size, sqlPlans);
+        checkMetrics(getSqlPlanHistory());
     }
 
     /**
@@ -649,21 +637,17 @@ public void checkSqlPlanHistoryDml(int size, boolean isSimpleQry) {
             sqlPlans = sqlPlans.stream().filter(e -> e.plan().contains(check)).collect(Collectors.toList());
         }
 
-        checkMetrics(size, sqlPlans);
+        assertTrue(sqlPlans.size() == size);
+
+        checkMetrics(sqlPlans);
     }
 
     /**
      * Checks metrics of provided SQL plan history entries.
      *
-     * @param size Number of SQL plan entries expected to be in the history.
      * @param sqlPlans Sql plans recorded in the history.
      */
-    public void checkMetrics(int size, List<SqlPlanHistoryView> sqlPlans) {
-        assertTrue(size == sqlPlans.size());
-
-        if (size == 0)
-            return;
-
+    public void checkMetrics(List<SqlPlanHistoryView> sqlPlans) {
         for (SqlPlanHistoryView plan : sqlPlans) {
             assertEquals(loc, plan.local());
             assertEquals(sqlEngine, plan.engine());

modules/core/src/main/java/org/apache/ignite/internal/processors/query/running/SqlPlan.java

@@ -45,6 +45,7 @@ public class SqlPlan {
      * @param qry Query.
      * @param schema Schema name.
      * @param loc Local query flag.
+     * @param engine SQL engine.
      */
     public SqlPlan(
         String plan,

modules/core/src/main/java/org/apache/ignite/internal/processors/query/running/SqlPlanHistoryTracker.java

@@ -24,6 +24,9 @@
 
 /** Class that manages recording and storing SQL plans. */
 public class SqlPlanHistoryTracker {
+    /** Empty map. */
+    private static final Map<SqlPlan, Long> EMPTY_MAP = Collections.emptyMap();
+
     /** SQL plan history. */
     private Map<SqlPlan, Long> sqlPlanHistory;
 
@@ -42,9 +45,7 @@ public SqlPlanHistoryTracker(int histSize) {
      * @param engine SQL engine.
      */
     public void addPlan(String plan, String qry, String schema, boolean loc, String engine) {
-        Map<SqlPlan, Long> emptyMap = Collections.emptyMap();
-
-        if (sqlPlanHistory == emptyMap)
+        if (sqlPlanHistory == EMPTY_MAP)
             return;
 
         SqlPlan sqlPlan = new SqlPlan(plan, qry, schema, loc, engine);
@@ -57,6 +58,11 @@ public Map<SqlPlan, Long> sqlPlanHistory() {
         return Collections.unmodifiableMap(sqlPlanHistory);
     }
 
+    /** */
+    public boolean enabled() {
+        return sqlPlanHistory != EMPTY_MAP;
+    }
+
     /**
      * @param histSize History size.
      */

modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/H2QueryInfo.java

@@ -74,6 +74,9 @@ public class H2QueryInfo implements TrackableQuery {
     /** Query id. */
     private final long queryId;
 
+    /** Query SQL plan. */
+    private volatile String plan;
+
     /**
      * @param type Query type.
      * @param stmt Query statement.
@@ -117,8 +120,21 @@ public long queryId() {
     }
 
     /** */
-    public String plan() {
-        return stmt.getPlanSQL();
+    public synchronized String plan() {
+        if (plan == null)
+            plan = planWithoutScanCount(stmt.getPlanSQL());
+
+        return plan;
+    }
+
+    /** */
+    public String schema() {
+        return schema;
+    }
+
+    /** */
+    public String sql() {
+        return sql;
     }
 
     /** */
@@ -179,7 +195,7 @@ public synchronized void resumeTracking() {
                 .append(", lazy=").append(lazy)
                 .append(", schema=").append(schema)
                 .append(", sql='").append(sql)
-                .append("', plan=").append(stmt.getPlanSQL());
+                .append("', plan=").append(plan());
 
         printInfo(msgSb);
 
@@ -193,6 +209,43 @@ public boolean isSuspended() {
         return isSuspended;
     }
 
+    /**
+     * If the same SQL query is executed sequentially within a single instance of {@link H2Connection} (which happens,
+     * for example, during consecutive local query executions), the next execution plan is generated using
+     * a {@link PreparedStatement} stored in the statement cache of this connection — H2Connection#statementCache.<br>
+     * <br>
+     * During the preparation of a PreparedStatement, a TableFilter object is created, where the variable scanCount
+     * stores the number of elements scanned within the query. If this value is not zero, the generated execution plan
+     * will contain a substring in the following format: "scanCount: X", where X is the value of the scanCount
+     * variable at the time of plan generation.<br>
+     * <br>
+     * The scanCount variable is reset in the TableFilter#startQuery method. However, since execution plans are
+     * generated and recorded asynchronously, there is no guarantee that plan generation happens immediately after
+     * TableFilter#startQuery is called.<br>
+     * <br>
+     * As a result, identical execution plans differing only by the scanCount suffix may be recorded in the SQL plan
+     * history. To prevent this, the suffix should be removed from the plan as soon as it is generated with the
+     * Prepared#getPlanSQL method.<br>
+     * <br>
+     *
+     * @param plan SQL plan.
+     *
+     * @return SQL plan without the scanCount suffix.
+     */
+    public String planWithoutScanCount(String plan) {
+        String res = null;
+
+        int start = plan.indexOf("\n    /* scanCount");
+
+        if (start != -1) {
+            int end = plan.indexOf("*/", start);
+
+            res = plan.substring(0, start) + plan.substring(end + 2);
+        }
+
+        return (res == null) ? plan : res;
+    }
+
     /**
      * Query type.
      */

modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/IgniteH2Indexing.java

@@ -469,13 +469,17 @@ private GridQueryFieldsResult executeSelectLocal(
                         qryInfo
                     );
 
-                    runningQueryManager().planHistoryTracker().addPlan(
-                        qryInfo.plan(),
-                        qry,
-                        qryDesc.schemaName(),
-                        true,
-                        IndexingQueryEngineConfiguration.ENGINE_NAME
-                    );
+                    if (runningQueryManager().planHistoryTracker().enabled()) {
+                        H2QueryInfo qryInfo0 = qryInfo;
+
+                        ctx.pools().getSystemExecutorService().submit(() ->
+                            runningQueryManager().planHistoryTracker().addPlan(
+                                qryInfo0.plan(),
+                                qryInfo0.sql(),
+                                qryInfo0.schema(),
+                                true,
+                                IndexingQueryEngineConfiguration.ENGINE_NAME));
+                    }
 
                     return new H2FieldsIterator(
                         rs,
@@ -2300,13 +2304,15 @@ else if (plan.hasRows()) {
             }
         }
         finally {
-            runningQueryManager().planHistoryTracker().addPlan(
-                dmlPlanInfo.toString(),
-                qryDesc.sql(),
-                qryDesc.schemaName(),
-                loc,
-                IndexingQueryEngineConfiguration.ENGINE_NAME
-            );
+            if (runningQueryManager().planHistoryTracker().enabled()) {
+                runningQueryManager().planHistoryTracker().addPlan(
+                    dmlPlanInfo.toString(),
+                    qryDesc.sql(),
+                    qryDesc.schemaName(),
+                    loc,
+                    IndexingQueryEngineConfiguration.ENGINE_NAME
+                );
+            }
         }
     }
 

modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/twostep/GridMapQueryExecutor.java

@@ -493,13 +493,17 @@ private void onQueryRequest0(
                             qryInfo
                         );
 
-                        h2.runningQueryManager().planHistoryTracker().addPlan(
-                            qryInfo.plan(),
-                            sql,
-                            schemaName,
-                            false,
-                            IndexingQueryEngineConfiguration.ENGINE_NAME
-                        );
+                        if (h2.runningQueryManager().planHistoryTracker().enabled()) {
+                            MapH2QueryInfo qryInfo0 = qryInfo;
+
+                            ctx.pools().getSystemExecutorService().submit(() ->
+                                h2.runningQueryManager().planHistoryTracker().addPlan(
+                                    qryInfo0.plan(),
+                                    qryInfo0.sql(),
+                                    qryInfo0.schema(),
+                                    false,
+                                    IndexingQueryEngineConfiguration.ENGINE_NAME));
+                        }
 
                         if (evt) {
                             ctx.event().record(new CacheQueryExecutedEvent<>(