Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

JDBC Oracle - Fetch explain plan for query

Im wondering how I can fetch the explain plan using Java. Reason I need this is because we have a framework where special users can craft reports. These reports sometimes build huge queries in which we want to explain on the fly and store the cost of. This way we can analyse the high cost queries later on and optimize.

Example code which gives me illegal column exception:

ResultSet rs = null;
   try {
        oracle = ConnectionManager.getConnection(ConnectionManager.Test);
        pstmt = oracle.prepareStatement("begin execute immediate 
        'explain plan for SELECT   1 from Dual'; end;");
        rs = pstmt.executeQuery();
        while (rs.next()) {
            System.out.println(rs.getString(1));
        }
like image 616
Chris Dale Avatar asked Dec 07 '10 11:12

Chris Dale


1 Answers

There is also a way to show real plan used to run last query in this session via DBMS_XPLAN.DISPLAY_CURSOR. The query of interest doesn't need to be prepended with EXPLAIN PLAN FOR.

try (Statement st = connection.createStatement()) {
    try (ResultSet rs = st.executeQuery(
            "select plan_table_output from table(dbms_xplan.display_cursor())")) {
        while (rs.next()) {
            System.out.println(rs.getString(1));
        }
    }
}

Note that the user needs to be granted the following permissions in order to use DBMS_XPLAN.DISPLAY_CURSOR:

GRANT SELECT ON v_$session TO USER;
GRANT SELECT ON v_$sql_plan TO USER;
GRANT SELECT ON v_$sql_plan_statistics_all TO USER;
GRANT SELECT ON v_$sql TO USER;

Credits go to https://myoracledbablog.wordpress.com/2016/07/26/dbms_xplan-and-the-user-has-no-select-privilege-on-v-error/.

See also https://blogs.oracle.com/optimizer/how-do-i-display-and-read-the-execution-plans-for-a-sql-statement.


But I've experienced that calling dbms_xplan.display_cursor() right after the executed query may still return unrelated results a in case a multi-thread app uses a shared connection pool.

This can be worked around by searching the most recent sql_id in v$sql system view and providing it as parameter to dbms_xplan.display_cursor.

So here is a ready to use java code to log actual execution plan of recently executed query by its sql (maybe partial).

public void explainActualPlan(String sql, boolean sqlIsPartial, Logger log) {
    if (!log.isTraceEnabled()) return;
    try (Connection connection = dataSource.getConnection()) {
        String sqlId;
        String sqlFilter = sqlIsPartial
                ? "sql_text like '%' || ? || '%'"
                //+ " and parsing_schema_id = sys_context('USERENV', 'CURRENT_SCHEMAID')"
                : (sql.length() <= 1000 ? "sql_text = ?" : "dbms_lob.compare(sql_fulltext, ?) = 0");
        try (PreparedStatement st = connection.prepareStatement(
                "select sql_id from v$sql where " + sqlFilter +
                        " order by last_active_time desc fetch next 1 row only")) {
            st.setString(1, sql);
            try (ResultSet rs = st.executeQuery()) {
                if (rs.next()) {
                    sqlId = rs.getString(1);
                } else {
                    log.warn("Can't find sql_id for sql '{}'. Has it really been just executed?", sql);
                    return;
                }
            }
        }
        String planFormat = "TYPICAL";
        if (sql.contains("GATHER_PLAN_STATISTICS")) {
            planFormat += " ALLSTATS LAST +cost +bytes OUTLINE";
        }
        try (PreparedStatement st = connection.prepareStatement(
                "select plan_table_output from table(dbms_xplan.display_cursor(" +
                        "sql_id => ?, format => '" + planFormat + "'))")) {
            st.setString(1, sqlId);
            try (ResultSet rs = st.executeQuery()) {
                StringBuilder sb = new StringBuilder("Last query plan:\n");
                while (rs.next()) {
                    sb.append(rs.getString(1)).append('\n');
                }
                log.trace(sb.toString());
            }
        }
    } catch (Exception e) {
        log.warn("Failed to explain query plan for '{}'", sql, e);
        log.warn("Check that permissions are granted to the current db user:\n"
                + "GRANT SELECT ON v_$session TO <USER>;\n"
                + "GRANT SELECT ON v_$sql_plan TO <USER>;\n"
                + "GRANT SELECT ON v_$sql_plan_statistics_all TO <USER>;\n"
                + "GRANT SELECT ON v_$sql TO <USER>;\n"
        );
    }
}

Some notes:

  • Oracle always converts prepared statement params from ? to :n syntax before storing the query text in v$sql, so searching by sql with ?'s won't find any matches
  • both v$sql.sql_text (truncated to first 1000 chars) and v$sql.sql_fulltext (full CLOB) store sql text without line breaks, so it may be needed perform a join with V$SQLTEXT_WITH_NEWLINES in case you use them in the query text
  • LIKE matching is used in partial mode, so it may be needed to escape '%' and '_' special chars
  • I've checked that Oracle allows to include any unknown strings in the hints comment like /*+ labuda FIRST_ROWS(200) */. It would still apply known hints in case the appendix is valid identifier (is alphanumeric and starts with letter). This may be useful for tracking queries of interest by appending some hashcode to hints clause.
  • v@sql could be additionally filtered by and parsing_schema_id = sys_context('USERENV', 'CURRENT_SCHEMAID') but this would exclude some plans in case DB instance is used by several similar apps in different schemas with exactly matching sql requests
  • the code above supplies additional details in plan output in case sql was executed with GATHER_PLAN_STATISTICS hint

Here is an example of above code output for a query from my another answer:

22:54:53.558 TRACE o.f.adminkit.AdminKitSelectorQuery - Last query plan:
SQL_ID  c67mmq4wg49sx, child number 0
-------------------------------------
select * from (select * from (select /*+ FIRST_ROWS(200) 
INDEX_RS_DESC("FR_MESSAGE_PART" ("TS")) GATHER_PLAN_STATISTICS */ "ID", 
"MESSAGE_TYPE_ID", "TS", "REMOTE_ADDRESS", "TRX_ID", 
"PROTOCOL_MESSAGE_ID", "MESSAGE_DATA_ID", "TEXT_OFFSET", "TEXT_SIZE", 
"BODY_OFFSET", "BODY_SIZE", "INCOMING" from "FR_MESSAGE_PART" where 
"TS" + 0 >= :1 and "TS" < :2 and "ID" >= 376894993815568384 and "ID" < 
411234940974268416 order by "TS" DESC) where ROWNUM <= 200) offset 180 
rows

Plan hash value: 2499404919

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                 | Name                  | Starts | E-Rows |E-Bytes|E-Temp | Cost (%CPU)| E-Time   | Pstart| Pstop | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                          |                       |      1 |        |       |       |   640K(100)|          |       |       |     20 |00:00:00.01 |     322 |       |       |          |
|*  1 |  VIEW                                     |                       |      1 |    200 |   130K|       |   640K  (1)| 00:00:26 |       |       |     20 |00:00:00.01 |     322 |       |       |          |
|   2 |   WINDOW NOSORT                           |                       |      1 |    200 |   127K|       |   640K  (1)| 00:00:26 |       |       |    200 |00:00:00.01 |     322 |   142K|   142K|          |
|   3 |    VIEW                                   |                       |      1 |    200 |   127K|       |   640K  (1)| 00:00:26 |       |       |    200 |00:00:00.01 |     322 |       |       |          |
|*  4 |     COUNT STOPKEY                         |                       |      1 |        |       |       |            |          |       |       |    200 |00:00:00.01 |     322 |       |       |          |
|   5 |      VIEW                                 |                       |      1 |    780K|   487M|       |   640K  (1)| 00:00:26 |       |       |    200 |00:00:00.01 |     322 |       |       |          |
|*  6 |       SORT ORDER BY STOPKEY               |                       |      1 |    780K|    68M|    89M|   640K  (1)| 00:00:26 |       |       |    200 |00:00:00.01 |     322 | 29696 | 29696 |26624  (0)|
|   7 |        PARTITION RANGE ITERATOR           |                       |      1 |    780K|    68M|       |   624K  (1)| 00:00:25 |     3 |     2 |    400 |00:00:00.01 |     322 |       |       |          |
|*  8 |         COUNT STOPKEY                     |                       |      2 |        |       |       |            |          |       |       |    400 |00:00:00.01 |     322 |       |       |          |
|*  9 |          TABLE ACCESS BY LOCAL INDEX ROWID| FR_MESSAGE_PART       |      2 |    780K|    68M|       |   624K  (1)| 00:00:25 |     3 |     2 |    400 |00:00:00.01 |     322 |       |       |          |
|* 10 |           INDEX RANGE SCAN DESCENDING     | IX_FR_MESSAGE_PART_TS |      2 |    559K|       |       | 44368   (1)| 00:00:02 |     3 |     2 |    400 |00:00:00.01 |       8 |       |       |          |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Outline Data
-------------

  /*+
      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('12.1.0.2')
      DB_VERSION('12.1.0.2')
      OPT_PARAM('optimizer_dynamic_sampling' 0)
      OPT_PARAM('_optimizer_dsdir_usage_control' 0)
      FIRST_ROWS(200)
      OUTLINE_LEAF(@"SEL$3")
      OUTLINE_LEAF(@"SEL$2")
      OUTLINE_LEAF(@"SEL$1")
      OUTLINE_LEAF(@"SEL$4")
      NO_ACCESS(@"SEL$4" "from$_subquery$_004"@"SEL$4")
      NO_ACCESS(@"SEL$1" "from$_subquery$_001"@"SEL$1")
      NO_ACCESS(@"SEL$2" "from$_subquery$_002"@"SEL$2")
      INDEX_RS_DESC(@"SEL$3" "FR_MESSAGE_PART"@"SEL$3" ("FR_MESSAGE_PART"."TS"))
      END_OUTLINE_DATA
  */

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("from$_subquery$_004"."rowlimit_$$_rownumber">180)
   4 - filter(ROWNUM<=200)
   6 - filter(ROWNUM<=200)
   8 - filter(ROWNUM<=200)
   9 - filter("ID">=376894993815568384)
  10 - access("TS"<:2)
       filter((INTERNAL_FUNCTION("TS")+0>=:1 AND "TS"<:2))
like image 89
Vadzim Avatar answered Oct 12 '22 08:10

Vadzim