obdiagは、OceanBase専用に設計されたブラックボックス診断ツールです。その機能は、OceanBaseのログ、SQL監査、およびOceanBaseプロセススタックなどの情報のスキャン、収集、分析をカバーしています。OCPやobdでのデプロイ、あるいはドキュメントに従って手動でデプロイする場合でも、obdiagはワンクリックで診断情報の収集と分析を迅速に完了できます。
このドキュメントでは、obdiagを使用してOceanBaseデータベースのフルリンクトレースを迅速に実行する方法を説明します。
obdiagのインストールとデプロイ
obdiagをダウンロードし、ダウンロードしたバージョンがv.1.5.0以降であることを確認してください。
公式ドキュメントアジャイル診断ツールobdiagを参照して、obdiagのインストール、デプロイ、設定を完了してください。
操作手順
ステップ1（オプション）：テナントのTraceをリセットする
包括的な診断を行う際にすべての結果を出力したい場合は、テナントのTraceをリセットする操作を実行できます。
OBServerに接続した後、次のSQLコマンドを実行します：
-- Traceを無効にする
call dbms_monitor.ob_tenant_trace_disable();
-- 現在のテナント内の時間消費情報を記録し、すべてを記録してすべて出力する。
call dbms_monitor.ob_tenant_trace_enable(1, 1, 'ALL');
ステップ2：SQLステートメントを照会してテストを行う
ここでは、SQLクエリステートメントを例に、フルリンク機能の診断方法を示します。
select * from tx where c1=1 and c1=2;
-- SQL Auditでは、`query_sql` を使用して疑わしい遅延SQLの `flt_trace_id` を検索します
SELECT query_sql, flt_trace_id FROM oceanbase.gv$ob_sql_audit WHERE query_sql LIKE 'select * from tx where c1=1 and c1=%';
+--------------------------------------+--------------------------------------+
| query_sql | flt_trace_id |
+--------------------------------------+--------------------------------------+
| select * from tx where c1=1 and c1=2 | 00060e1a-dead-7cbd-5d74-6d64084eccfa |
+--------------------------------------+--------------------------------------+
1 row in set (0.206 sec)
ステップ3：フルトレースコマンドを実行する
OBServerを終了し、以下のコマンドを実行してフルトレースを行います。
-- ステップ2で取得した `flt_trace_id` と設定済みの環境を使用してフルトレースコマンドを実行します：
$ obdiag analyze flt_trace --flt_trace_id 00060e1a-dead-7cbd-5d74-6d64084eccfa
実行結果は次のとおりです：
2024-01-04 16:54:21,217 [INFO] Use analyze_flt_result_20240104165421 as pack dir.
2024-01-04 16:54:21,218 [INFO] Sending Collect Shell Command to node 172.xx.xxx.xxx ...
2024-01-04 16:54:21,227 [INFO] Connected (version 2.0, client OpenSSH_7.4)
2024-01-04 16:54:21,300 [INFO] Authentication (publickey) failed.
2024-01-04 16:54:21,317 [INFO] Authentication (password) successful!
2024-01-04 16:54:21,317 [INFO] [remote host 172.xx.xxx.xxx] execute cmd = [mkdir -p /tmp/trace_merged_cache]
2024-01-04 16:54:21,365 [INFO] [remote host 172.xx.xxx.xxx] execute cmd = [grep '00060e1a-dead-7cbd-5d74-6d64084eccfa' /home/admin/oceanbase/log/*trace.log* > /tmp/trace_merged_cache/00060e1a-dead-7cbd-5d74-6d64084eccfa ]
2024-01-04 16:54:21,412 [INFO] Please wait a moment, download file [/tmp/trace_merged_cache/00060e1a-dead-7cbd-5d74-6d64084eccfa] from server 172.xx.xxx.xxx to [analyze_flt_result_20240104165421/172.xx.xxx.xxx/OBSERVER-00060e1a-dead-7cbd-5d74-6d64084eccfa]
2024-01-04 16:54:21,459 [INFO] [chan 2] Opened sftp connection (server version 3)
Download 172.xx.xxx.xxx:/tmp/trace_merged_cache/00060e1a-dead-7cbd-5d74-6d64084eccfa
Downloading [====================] 100.0% [9.18 KB ]
2024-01-04 16:54:21,463 [INFO] [chan 2] sftp session closed.
2024-01-04 16:54:21,463 [INFO] [remote host 172.xx.xxx.xxx] execute cmd = [rm -rf /tmp/trace_merged_cache/OBSERVER-00060e1a-dead-7cbd-5d74-6d64084eccfa]
2024-01-04 16:54:21,469 [INFO] [chan 2] sftp session closed.
2024-01-04 16:54:21,475 [INFO] parse file: analyze_flt_result_20240104165421/172.xx.xxx.xxx/OBSERVER-00060e1a-dead-7cbd-5d74-6d64084eccfa
2024-01-04 16:54:21,476 [INFO] file:analyze_flt_result_20240104165421/172.xx.xxx.xxx/OBSERVER-00060e1a-dead-7cbd-5d74-6d64084eccfa trace:00060e1a-dead-7cbd-5d74-6d64084eccfa total:21
root node id: 00060e1a-dead-7cbd-0d98-21b2933fca47
Top time-consuming leaf span:
+----+----------------+--------------+---------------------------+
| ID | Leaf Span Name | Elapsed Time | HOSTS |
+----+----------------+--------------+---------------------------+
| 10 | optimize | 531 μs | OBSERVER (
172.xx.xxx.xxx) |
| 8 | resolve | 289 μs | OBSERVER (172.xx.xxx.xxx) |
| 9 | rewrite | 460 μs | OBSERVER (172.xx.xxx.xxx) |
| 11 | code_generate | 126 μs
| OBSERVER (172.xx.xxx.xxx) |
| 12 | pc_add_plan | 59 μs | OBSERVER (172.xx.xxx.xxx) |
+----+----------------+--------------+---------------------------+
Tags & Logs:
-------------------------------------
10 - optimize Elapsed: 531 μs
OBSERVER (172.xx.xxx.xxx)
8 - resolve Elapsed: 289 μs
OBSERVER (172.xx.xxx.xxx)
9 - rewrite Elapsed: 460 μs
OBSERVER (172.xx.xxx.xxx)
11 - code_generate Elapsed: 126 μs
OBSERVER (172.xx.xxx.xxx)
12 - pc_add_plan Elapsed: 59 μs
OBSERVER (172.xx.xxx.xxx)
Details:
+---+------------------------------+-------------+--------------------------+
| ID| Span Name | Elapsed Time| HOSTS |
+---+------------------------------+-------------+--------------------------+
| 1 | TRACE | - | |
| 2 | └─com_query_process | 2.040 ms | OBSERVER (172.xx.xxx.xxx)|
| 3 | └─mpquery_single_stmt | 2.026 ms | |
| 4 | ├─sql_compile | 1.787 ms | |
| 5 | │ ├─pc_get_plan | 5 μs | OBSERVER (172.xx.xxx.xxx)|
| 6 | │ └─hard_parse | 1.738 ms | |
| 7 | │ ├─parse | 57 μs | OBSERVER (172.xx.xxx.xxx)|
| 8 | │ ├─resolve | 289 μs | OBSERVER (172.xx.xxx.xxx)|
| 9 | │ ├─rewrite | 460 μs | OBSERVER (172.xx.xxx.xxx)|
| 10| │ ├─optimize | 531 μs | OBSERVER (172.xx.xxx.xxx)|
| 11| │ ├─code_generate | 126 μs | OBSERVER (172.xx.xxx.xxx)|
| 12| │ └─pc_add_plan | 59 μs | OBSERVER (172.xx.xxx.xxx)|
| 13| └─sql_execute | 179 μs | |
| 14| ├─open | 21 μs | OBSERVER (172.xx.xxx.xxx)|
| 15| ├─response_result | 80 μs | |
| 16| │ └─do_local_das_task | 40 μs | OBSERVER (172.xx.xxx.xxx)|
| 17| └─close | 42 μs | |
| 18| ├─close_das_task | 5 μs | OBSERVER (172.xx.xxx.xxx)|
| 19| └─end_transaction | 2 μs | OBSERVER (172.xx.xxx.xxx)|
+---+------------------------------+-------------+--------------------------+
Tags & Logs:
-------------------------------------
1 -
2 - com_query_process Elapsed: 2.040 ms
OBSERVER (172.xx.xxx.xxx)
tags: [{'sess_id': 32 ...
3 - mpquery_single_stmt Elapsed: 2.026 ms
4 - sql_compile Elapsed: 1.787 ms
tags: [{'sql_text': 'select * from tx where c1=1 and c1=2 ...
5 - pc_get_plan Elapsed: 5 μs
OBSERVER (172.xx.xxx.xxx)
6 - hard_parse Elapsed: 1.738 ms
7 - parse Elapsed: 57 μs
OBSERVER (172.xx.xxx.xxx)
Result too large, wait a moment ...
For more details, please run cmd ' cat analyze_flt_result_20240104165421/00060e1a-dead-7cbd-5d74-6d64084eccfa.txt '
If you want to view detailed obdiag logs, please run:' obdiag display-trace --trace_id 4335f2a3-6d17-3904-8ff9-d5b25aeffd21 '
ステップ4：フルトレースの詳細を確認する
$ cat analyze_pack_20231008171201/result_details.txt
フルトレースの結果には、時間消費量が上位5つのLeaf Spanと、各Spanの詳細情報およびタグが含まれます。