OceanBase SQL Trace

SQL Trace 能夠交互式的提供上一次執(zhí)行的 SQL 請(qǐng)求執(zhí)行過程信息及各階段的耗時(shí)。

SQL Trace 開關(guān)

SQL Trace 功能默認(rèn)是關(guān)閉的，可通過 session 變量來控制其打開和關(guān)閉。

• 打開 SQL Trace 功能的語句如下：

  obclient>SET ob_enable_trace_log = 1;

• 關(guān)閉 SQL Trace 功能的語句如下：

  obclient>SET ob_enable_trace_log = 0;

Show Trace

當(dāng) SQL Trace 功能打開后，執(zhí)行需要診斷的 SQL，然后通過 ?SHOW TRACE? 能夠查看該 SQL 執(zhí)行的信息。這些執(zhí)行信息以表格方式輸出，每列說明如下：

示例

1. 打開 SQL Trace：

   obclient> SET ob_enable_trace_log = 1;

2. 執(zhí)行目標(biāo) SQL：

   obclient> CREATE TABLE t1(c1 INT,c2 INT,c3 INT); 
   Query OK, 0 rows affected (0.02 sec) 
   
   obclient> INSERT INTO t1 VALUES(1,1,1); 
   Query OK, 1 rows affected (0.02 sec) 
   
   obclient> INSERT INTO t1 VALUES(2,2,2); 
   Query OK, 1 rows affected (0.02 sec) 
   
   obclient>SELECT * FROM t1 WHERE c1 = 1; 
   +----+------+------+ 
   | c1 |  c2  |  c3  | 
   +----+------+------+ 
   | 1  |  1   |   1  |
   +----+------+------+

3. 顯示 Trace：

obclient> SHOW TRACE; 
+------------------------------+---------------------------------------------------------------------------------------------------+ 
| TITLE | KEYVALUE | TIME | 
+------------------------------+----------------------------------------------------------------------------+------+ 
| process begin | in_queue_time:17, receive_ts:1612420489580707, enqueue_ts:1612420489580709 | 0 | 
| query begin | trace_id:YB42AC1E87E6-0005B8AB2D57844F | 1 | 
| parse begin | stmt:"set ob_enable_trace_log = 1", stmt_len:27 | 62 | 
| pc get plan begin | NULL | 9 | 
| pc get plan end | NULL | 19 | 
| transform_with_outline begin | NULL | 1 | 
| transform_with_outline end | NULL | 31 | 
| resolve begin | NULL | 21 | 
| resolve end | NULL | 33 | 
| execution begin | arg1:false, end_trans_cb:false | 14 | 
| start_auto_end_plan begin | NULL | 39 | 
| start_auto_end_plan end | NULL | 1 | 
| execution end | NULL | 11 | 
| query end | NULL | 39 | 
+------------------------------+---------------------------------------------------------------------------------------------+------+

示例中 ?SHOW TRACE? 結(jié)果說明如下：
• Title 列包含整個(gè) SQL 執(zhí)行經(jīng)歷的各個(gè)階段的信息以及該 SQL 真實(shí)的執(zhí)行路徑。上述示例的結(jié)果中有經(jīng)過 Resolve、Transform、Optimizer 和 Code Generate 四個(gè)流程，說明該 SQL 重新生成了計(jì)劃，沒有命中 plan cache。
• KeyValue 列包含一些執(zhí)行信息，可以用于排查問題：
  • ?trace_id? 可以作為 sql_audit 中的過濾條件，快速找到該 SQL 執(zhí)行信息，同時(shí)也可以通過該 ?trace_id? 快速查找相關(guān)的 observer 日志。
  • ?plan_id? 可以用于在 ?v$plan_cache_plan_explain? 中查看 plan cache 中緩存的具體執(zhí)行計(jì)劃。
  • ?phy_plan_type? 指出該次執(zhí)行計(jì)劃的類型（1 表示本地計(jì)劃/2 表示遠(yuǎn)程計(jì)劃/3 表示分布式計(jì)劃），可以輔助 SQL 診斷。
• Time 列顯示上一個(gè)階段點(diǎn)到這次階段點(diǎn)執(zhí)行耗時(shí)。例如，resolve end 對(duì)應(yīng)的 206 us 表示的是 resolve begin 到 resolve 耗時(shí)。如果某個(gè) SQL 執(zhí)行很慢，則通過查看 time 列，能夠快速定位出具體是哪個(gè)階段執(zhí)行較慢，然后再進(jìn)行具體分析。此例中，執(zhí)行耗時(shí)主要在生成計(jì)劃過程中，因此只需要分析沒有命中 plan cache 的原因，可能是計(jì)劃淘汰后 第一次執(zhí)行該 SQL，或是 plan cache 不支持的 SQL。