obdiag is a command line-based diagnostic tool specifically designed for OceanBase Database. Its functionalities cover the scanning, collection, and analysis of OceanBase logs, SQL audits, and OceanBase process stacks. Whether you have deployed OceanBase Database using OCP, obd, or manual deployment according to the documentation, obdiag can quickly complete the collection and analysis of diagnostic information with a single click.
This topic will guide you on how to quickly perform an end-to-end tracing of OceanBase Database using obdiag.
Install and deploy obdiag
Download obdiag V1.5.0 or later.
Refer to obdiag official documentation to complete the installation, deployment, and configuration of obdiag.
Procedure
Step 1: (Optional) Reset tenant trace
If you want to print all results during a comprehensive tracing, you can perform the Reset Tenant Trace operation.
After connecting to an OBServer node, execute the following SQL commands:
-- Disable Trace
call dbms_monitor.ob_tenant_trace_disable();
-- Record all time-consuming information in the current tenant and print them.
call dbms_monitor.ob_tenant_trace_enable(1, 1, 'ALL');
Step 2: Query SQL statements for testing
Here, a SQL query statement is used as an example to demonstrate how to perform an end-to-end tracing.
select * from tx where c1=1 and c1=2;
-- In SQL Audit, find the `flt_trace_id` of the suspected slow SQL using `query_sql`
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)
Step 3: Execute the end-to-end diagnostic command
Exit the OBServer node and execute the following command to perform the end-to-end tracing:
-- Use the `flt_trace_id` obtained in Step 2 and the configured environment to execute the full-chain diagnostic command:
$ obdiag analyze flt_trace --flt_trace_id 00060e1a-dead-7cbd-5d74-6d64084eccfa
The result will be as follows:
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 '
Step 4: View end-to-end tracing details
$ cat analyze_pack_20231008171201/result_details.txt
The end-to-end tracing results will include the TOP 5 time-consuming Leaf Spans, as well as detailed information and tags for each Span.