寻SQL执行线索的武器库

寻SQL执行线索的武器库

碰到一些SQL问题，有时常规的方式，例如执行计划，不足以给出问题的线索。因此，可能还需要跟踪这条SQL，通过Oracle提供的trace，了解它内部执行的机制，从中寻线索。

需求：用户TEST通过dbeaver登录到数据库，需要跟踪它所执行的SQL。

（1）确定TEST用户通过dbeaver执行SQL的会话信息。

sys或者具有v$访问权限的用户，执行如下SQL，

select p.PID,p.SPID,s.SID, s.serial#, s.program, 
from v$process p,v$session s
where s.paddr = p.addr
and s.username=	TEST	;

得到会话信息，根据实际情况，确认第二条记录，是需要的会话，

（2）sys或者高级别账号，执行如下语句，其中session_id是（1）的s.sid，serial_num是（1）的s.serial#，

begin
dbms_monitor.session_trace_enable(session_id =>64,serial_num =>5061,binds =>TRUE,waits =>TRUE,plan_stat =>	all_executi	);
end;
/

（）TEST用户执行语句，

SELECT * FROM t;（t表不存在）
SELECT * FROM test;

（4）如上SQL执行的数据都存储到（1）的。从如下的展示，仅仅是（）的这两条简单的语句，就写了K的内容到trace，足以见得Oracle为了执行语句，其实内部机制还是很复杂的，

[oracle@VM-24-12-centos ~]$ ls -lrht /opt/oracle/diag/rdbms/bisalcdb/BISALCDB/trace/BISALCDB_ora_
-rw-r----- 1 oracle oinstall K Mar  5 22:0 /opt/oracle/diag/rdbms/bisalcdb/BISALCDB/trace/BISALCDB_ora_

打开trace，可以看到第一条SQL提示了PARSE ERROR，第二条SQL展示了具体执行的信息（包括执行计划、PARSE/EXEC/FETCH等语句执行阶段的消耗），可以有助于进一步对SQL进行探索，

vi /opt/oracle/diag/rdbms/bisalcdb/BISALCDB/trace/BISALCDB_ora_
...
=====================
PARSE ERROR #140644761776904:len=15 dep=0 uid=112 oct= lid=112 tim=298470188260 err=942
SELECT * FROM t
WAIT #140644761776904: nam=	SQL*et break/reset to client	 ela= 6 driver id=14169756 break?=1 p=0 obj#=0 tim=29847018896
WAIT #140644761776904: nam=	SQL*et break/reset to client	 ela= 171292 driver id=14169756 break?=0 p=0 obj#=0 tim=2984705970
WAIT #140644761776904: nam=	SQL*et message to client	 ela=  driver id=14169756 #bytes=1 p=0 obj#=0 tim=29847059777*** 202-0-05T22:0:19.8501108:00 (BISALPDB1())
WAIT #140644761776904: nam=	SQL*et message from client	 ela= 7794254 driver id=14169756 #bytes=1 p=0 obj#=0 tim=298478155022
CLOSE #140644761776904:c=6,e=6,dep=0,type=0,tim=298478155121
...
=====================
PARSIG I CURSOR #140644761776904 len=18 dep=0 uid=112 oct= lid=112 tim=2984950425 hv=2851490487 ad=	68c94b0	 sqlid=	46ncd1ynzckpr	
SELECT * FROM test
ED OF STMT
PARSE #140644761776904:c=12575,e=2791,p=,cr=47,cu=0,mis=1,r=0,dep=0,og=1,plh=157081020,tim=2984950425
EXEC #140644761776904:c=10,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=157081020,tim=2984950468
WAIT #140644761776904: nam=	SQL*et message to client	 ela= 2 driver id=14169756 #bytes=1 p=0 obj#=0 tim=29849504420
FETCH #140644761776904:c=2,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=157081020,tim=29849504440
STAT #140644761776904 id=1 cnt=0 pid=0 pos=1 obj=7296 op=	TABLE ACCESS FULL TEST (cr=0 pr=0 pw=0 str=1 time=1 us cost=2 size=1 card=1)	
...

（5）关闭trace跟踪，则需要执行如下这条语句，

begin
dbms_monitor.session_trace_disable(session_id =>64,serial_num =>5061);
end;
/

可以将上述过程进行封装，通过工具、脚本等形式，快速调用，丰富我们排查问题的工具箱。

除此之外，10046和1005，也是我们探究问题需要具备的武器，

《如何生成其他会话的10046？》

《PL/SQL中SQL语句1005创建方法》

《有关1005事件，你知道这两个知识点么？》

《探索索引的奥秘 - 1005事件》

像常见的ORA-00060，同样通过Oracle自动生成的trace文件，可以从中到锁之间的关联，进而有助于判断应用设计的逻辑顺序问题，

《了解ORA-00060和trace跟踪文件》

如果您认为这篇文章有些帮助，还请不吝点下文章末尾的点赞和在看，或者直接转发pyq，

近期更新的文章：

《MySQL唯一索引有重复值且不是bug的场景》

《《数字中国建设整体布局规划》》

《MySQL日志 - Error Log错误日志》

《MySQL日志 - General Query Log》

《最近碰到的一些问题》

近期的热文：

《推荐一篇Oracle RAC Cache Fusion的经典论文》

《红警游戏开源代码带给我们的震撼》

文章分类和索引：

《1100篇文章分类和索引》