DBA手记:SQL_TRACE跟踪与诊断案例
客户的应用是一个后台新闻发布系统，主要性能问题是通过连接访问新闻页极其缓慢，通常需要十数秒才能返回，这是用户不能忍受的。客户操作系统是SunOS 5.8，
数据库版本为8.1.7。
面对这个问题，首先想到的是SQL问题，但如何定位具体的问题SQL成为我们考虑的主要目标，通过Statspack采样是一个全局手段，而通过sql_trace则可以实时对会话进行跟踪。诊断时是晚上，在无集中用户访问情况下，让用户在前台进行相关页面的访问，同时进行进程跟踪。
查询v$session视图，获取进程信息：
SQL> select sid,serial#,username from v$session where username is not null;
SID SERIAL# USERNAME
---------- ---------- ------------------------------
7 284 IFLOW
11 214 IFLOW
12 164 SYS
16 1042 IFLOW
然后对相应的应用会话启用sql_trace跟踪如下： SQL> exec dbms_system.set_sql_trace_in_session(7,284,true) SQL> exec dbms_system.set_sql_trace_in_session(11,214,true) SQL> exec dbms_system.set_sql_trace_in_session(16,1042,true) 应用执行一段时间后，关闭sql_trace： SQL> exec dbms_system.set_sql_trace_in_session(7,284,false) SQL> exec dbms_system.set_sql_trace_in_session(11,214,false) SQL> exec dbms_system.set_sql_trace_in_session(16,1042,false)
检查trace文件，可以找到跟踪过程中前台执行的SQL调用，检查发现以下语句是可疑的性能瓶颈点：
******************************************************************************** select auditstatus,categoryid,auditlevel from categoryarticleassign a,category b where b.id=a.categoryid and articleId= 20030700400141 and auditstatus>0 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.81 0.81 0 3892 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 0.81 0.81 0 3892 0 1 ********************************************************************************
这里的查询显然是根据articleId进行新闻读取的，但是注意到逻辑读有3892，这是较高的一个数字，这个内容引起了我的注意。
接下来的类似查询跟踪得到的执行计划显示，全表访问被执行：
select auditstatus,categoryid from
categoryarticleassign where articleId=20030700400138 and categoryId in ('63',
'138','139','140','141','142','143','144','168','213','292','341''-1')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 4.91 4.91 0 2835 7 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 4.91 4.91 0 2835 7 1
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL CATEGORYARTICLEASSIGN
登录数据库，检查相应表结构，看是否存在有效的索引，以下输出中的IDX_ARTICLEID基于ARTICLEID创建，但是在以上查询中都没有被用到：
SQL> select index_name,table_name,column_name from user_ind_columns
2 where table_name=upper('categoryarticleassign');
INDEX_NAME TABLE_NAME COLUMN_NAME
------------------------------ ------------------------------ --------------------
IDX_ARTICLEID CATEGORYARTICLEASSIGN ARTICLEID
IND_ARTICLEID_CATEG CATEGORYARTICLEASSIGN ARTICLEID
IND_ARTICLEID_CATEG CATEGORYARTICLEASSIGN CATEGORYID
IDX_SORTID CATEGORYARTICLEASSIGN SORTID
PK_CATEGORYARTICLEASSIGN CATEGORYARTICLEASSIGN ARTICLEID
PK_CATEGORYARTICLEASSIGN CATEGORYARTICLEASSIGN CATEGORYID
PK_CATEGORYARTICLEASSIGN CATEGORYARTICLEASSIGN ASSIGNTYPE
检查如下表结构:
SQL> desc categoryarticleassign
Name Null Type
----------------------------------------- -------- -----