SQL Trace

SQL Trace interactively provides the trace information about the previously executed SQL statement, including the time consumed at each stage of the trace, to facilitate performance analysis and tuning. You can use the SHOW TRACE statement to conveniently locate performance bottlenecks.

By default, the SQL Trace feature is disabled and can be controlled by session variables.

• Execute the following statement to enable SQL Trace:

  obclient> SET ob_enable_show_trace = 1;
  

• Execute the following statement to disable SQL Trace:

  obclient> SET ob_enable_show_trace = 0;
  

The following example uses SHOW TRACE to show the trace information about an SQL statement.

1. Enable SQL Trace:

   obclient> SET ob_enable_show_trace = 1;
   Query OK, 0 rows affected
   

2. Execute an SQL statement:

   obclient> CREATE TABLE t1(c1 INT,c2 INT,c3 INT);
   Query OK, 0 rows affected
   
   obclient> INSERT INTO t1 VALUES(1,1,1);
   Query OK, 1 rows affected
   
   obclient> INSERT INTO t1 VALUES(2,2,2);
   Query OK, 1 rows affected
   
   obclient> SELECT/*+PARALLEL(2)*/ COUNT(*) FROM t1;
   +----------+
   | COUNT(*) |
   +----------+
   |        2 |
   +----------+
   1 row in set
   

3. Show the trace:

   obclient> SHOW TRACE;
   +-------------------------------------------------------+---------------------+-------------+
   | OPERATION                                             | START_TIME          | ELAPSE_TIME |
   +-------------------------------------------------------+---------------------+-------------+
   | com_query_process                                     | 2023/03/07 16:27:43 | 5241 µs     |
   | └── mpquery_single_stmt                               | 2023/03/07 16:27:43 | 5208 µs     |
   |     ├── sql_compile                                   | 2023/03/07 16:27:43 | 4149 µs     |
   |     │   ├── pc_get_plan                               | 2023/03/07 16:27:43 | 108 µs      |
   |     │   └── hard_parse                                | 2023/03/07 16:27:43 | 3952 µs     |
   |     │       ├── parse                                 | 2023/03/07 16:27:43 | 97 µs       |
   |     │       ├── resolve                               | 2023/03/07 16:27:43 | 492 µs      |
   |     │       ├── rewrite                               | 2023/03/07 16:27:43 | 598 µs      |
   |     │       ├── optimize                              | 2023/03/07 16:27:43 | 2022 µs     |
   |     │       │   ├── inner_execute_read                | 2023/03/07 16:27:43 | 485 µs      |
   |     │       │   │   ├── sql_compile                   | 2023/03/07 16:27:43 | 140 µs      |
   |     │       │   │   │   └── pc_get_plan               | 2023/03/07 16:27:43 | 81 µs       |
   |     │       │   │   ├── open                          | 2023/03/07 16:27:43 | 43 µs       |
   |     │       │   │   ├── get_das_id                    | 2023/03/07 16:27:43 | 17 µs       |
   |     │       │   │   └── do_local_das_task             | 2023/03/07 16:27:43 | 107 µs      |
   |     │       │   └── close                             | 2023/03/07 16:27:43 | 66 µs       |
   |     │       │       ├── close_das_task                | 2023/03/07 16:27:43 | 17 µs       |
   |     │       │       └── end_transaction               | 2023/03/07 16:27:43 | 6 µs        |
   |     │       ├── code_generate                         | 2023/03/07 16:27:43 | 197 µs      |
   |     │       └── pc_add_plan                           | 2023/03/07 16:27:43 | 74 µs       |
   |     └── sql_execute                                   | 2023/03/07 16:27:43 | 979 µs      |
   |         ├── open                                      | 2023/03/07 16:27:43 | 19 µs       |
   |         ├── response_result                           | 2023/03/07 16:27:43 | 768 µs      |
   |         │   ├── get_das_id                            | 2023/03/07 16:27:43 | 0 µs        |
   |         │   └── do_local_das_task                     | 2023/03/07 16:27:43 | 358 µs      |
   |         └── close                                     | 2023/03/07 16:27:43 | 145 µs      |
   |             └── close_das_task                        | 2023/03/07 16:27:43 | 19 µs       |
   +-------------------------------------------------------+---------------------+-------------+
   27 rows in set