如何对sql就行全链路追踪，监控sql耗时

OceanBase 技术问题
#1

【 使用环境 】生产环境 or 测试环境
【 OB or 其他组件 】
【 使用版本 】
【问题描述】如何对sql就行全链路追踪，监控sql耗时

5 个赞
#3

一、全链路追踪
步骤 1 使用 obclient 连接 mysql 租户。
obclient -h -P2883 -uroot@mysql#obcp_test -p -c -A -D test

步骤 2 查看租户默认的全链路 Trace 收集策略。
SELECT TENANT_NAME,LEVEL,SAMPLE_PERCENTAGE,RECORD_POLICY
FROM GV$OB_FLT_TRACE_CONFIG;

步骤 3 设置当前 Session 的全链路 Trace 收集策略为搜集所有 SQL 执行的 Trace，并确认设置生效。
CALL DBMS_MONITOR.OB_SESSION_TRACE_ENABLE(NULL,3,1,‘ALL’);

SELECT SVR_IP, TENANT, DB, USER, ID, STATE, LEVEL, SAMPLE_PERCENTAGE,
RECORD_POLICY FROM GV$OB_PROCESSLIST WHERE ID=CONNECTION_ID();
Ø 使用 CONNECTION_ID()函数返回当前 Session 的 ID。

步骤 4 执行以下 SQL 语句。
USE test;
SELECT count(*) FROM sbtest1 t1,sbtest2 t2;

步骤 5 在 SELECT 执行结束后，使用 SHOW TRACE 命令查看 SQL 执行的全链路 Trace，发现结果为空。
SHOW TRACE;

步骤 6 打开当前 Session 的在线 show trace 功能，并再次 SHOW TRACE，发现结果依然为空。
SET ob_enable_show_trace=on;
SHOW TRACE;

步骤 7 再次执行 SELECT，并在结束后立刻执行 SHOW TRACE 命令，终于可以看到全链路跟踪的 Trace。
SELECT count(*) FROM sbtest1 t1,sbtest2 t2;
SHOW TRACE;
Ø 请从 Trace 信息中获取 SQL 编译（解析、生成执行计划）的耗时，和 SQL 真正的执行耗时。

二、Sql监控
步骤 1 打开两个连接 mysql 租户的会话。
obclient -h -P2883 -uroot@mysql#obcp_test -p -c -A -D test

步骤 2 会话 1：执行一个慢 SQL，以便于会话 2 在 SQL 执行时进行监控。比如：
select /+query_timeout(6000000000)/ count(*) from sbtest1 t1,sbtest2 t2 where
t1.id<>t2.id and t1.k>t2.k ;

步骤 3 会话 2：在慢 SQL 的执行过程中，查询会话 1 的 id(Session ID)、trace_id、sql_id 等信息。
SELECT svr_ip,svr_port, id, state, command, time, total_time, sql_id, trace_id,
info FROM oceanbase.GV$OB_PROCESSLIST WHERE state = ‘active’;

步骤 4 会话 2：查看会话 1 中当前执行 SQL 的执行计划和执行统计，比较估算代价与实际代 sql_id 价的差
异。
SELECT DBMS_XPLAN.DISPLAY_ACTIVE_SESSION_PLAN(3222267850, ‘typical’,
‘172.28.15.214’, ‘2882’);

步骤 5 会话 2：使用 GV$OB_PROCESSLIST 中查到的 trace_id，在 GV$SQL_PLAN_MONITOR 查看会话
1 中慢 SQL 的执行算子的实时统计。
SELECT PLAN_LINE_ID, PLAN_OPERATION, SVR_IP, OUTPUT_ROWS, STARTS RESCAN_TIMES,
LAST_REFRESH_TIME - FIRST_REFRESH_TIME ELAPSED_TIME FROM
oceanbase.GV$SQL_PLAN_MONITOR WHERE TRACE_ID = ‘YB42AC1C0FD6-000625D4B24D0185-0-0’
ORDER BY PLAN_LINE_ID,SVR_IP;

步骤 6 会话 1：使用 Ctrl+C 取消当前慢 SQL 的执行。

步骤 7 任意会话：在 GV$OB_SQL_AUDIT 中查看慢 SQL 的整体执行情况。
SELECT SVR_IP, SVR_PORT, USEC_TO_TIME(REQUEST_TIME) AS REQUEST_TIME, TENANT_ID,
TRACE_ID, SQL_ID, PLAN_ID, PLAN_TYPE, ELAPSED_TIME, QUEUE_TIME, EXECUTE_TIME,
EXECUTE_TIME-TOTAL_WAIT_TIME_MICRO AS CPU_TIME, TOTAL_WAIT_TIME_MICRO,
RETURN_ROWS, AFFECTED_ROWS, RET_CODE, QUERY_SQL FROM oceanbase.GV$OB_SQL_AUDIT
WHERE SQL_ID= ‘34534DEC9BD5F5FE15833AB4B2984462’ AND TRACE_ID=‘YB42AC1C0FD4-
000625D4ABAF865C-0-0’;

步骤 8 任意会话：使用上一步从 GV$OB_SQL_AUDIT 查询得到的 svr_ip、svr_port、tenant_id、plan_id，
在 GV$PLAN_CACHE_PLAN_EXPLAIN 中查看慢 SQL 的物理执行计划。
SELECT PLAN_ID, PLAN_LINE_ID, OPERATOR, NAME, ROWS, COST FROM
oceanbase.GV$OB_PLAN_CACHE_PLAN_EXPLAIN WHERE SVR_IP=‘172.28.15.214’ AND
SVR_PORT=2882 AND TENANT_ID=1002 AND PLAN_ID=408 ORDER BY PLAN_LINE_ID;

步骤 9 登录到慢 SQL 执行所在的 OBServer 服务器（示例中为 172.28.15.212），在对应时间的 observer 进
程日志中检索慢 SQL 执行的 trace_id。
cd /home/admin/oceanbase/log;
ll -rt observer.log*
grep YB42AC1C0FD6-000625D4B24D0185-0-0 observer.log.20241107131212869
Ø [slow query]日志里详细统计了 sql 各个执行阶段的执行耗时。

5 个赞
#4

感谢

2 个赞
#5

学习

1 个赞
#6

支持一下

2 个赞
#7

厉害！！！学习了