SQL Trace

SQL Traceは、直前に実行されたSQLリクエストの実行プロセスにおける呼び出しチェーンと、その各段階での時間消費状況をインタラクティブに提供し、パフォーマンス分析やチューニングに役立ちます。SHOW TRACE機能を使用することで、パフォーマンスボトルネックを簡単に特定できます。

SQL Trace機能はデフォルトで無効になっています。session変数を使用して有効化および無効化を制御できます。

• SQL Trace機能を有効にするステートメントは以下のとおりです：

  obclient> SET ob_enable_show_trace = 1;
  

• SQL Trace機能を無効にするステートメントは以下のとおりです：

  obclient> SET ob_enable_show_trace = 0;
  

本記事では、以下の具体的な例を通じて、SHOW TRACEを使用して特定のSQLの実行情報を確認する方法を示します。

1. SQL Traceを開く：

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

2. 対象SQLを実行する：

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