SQL Trace

SQL Trace interactively provides execution information about the previous SQL query, including the time consumed at each stage.

Enable/disable SQL Trace

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;
  

Show Trace

To diagnose an SQL query, enable the SQL Trace feature, execute the SQL query, and execute the SHOW TRACE statement to view the execution information, which is displayed in a table. The following table describes each column of the output information:

Examples

1. Enable SQL Trace:

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

2. Execute the SQL query:

   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 * FROM t1 WHERE c1 = 1;
   +----+------+------+
   | c1 | c2   | c3   |
   +----+------+------+
   |  1 |    1 |    1 |
   +----+------+------+
   1 row in set
   

3. Show 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