我们通过几个案例来看一下SQL_TRACE在数据库诊断及优化过程中的应用。
问题描述
这是帮助一个公司进行优化的诊断案例，应用是一个后台新闻发布系统。前端展现是一个大型网站。JAVA开发应用，通过中间件连接池连接数据库。
操作系统:SunOS 5.8
数据库版本:8.1.7
系统症状：通过链接访问新闻页极其缓慢，后台发布管理具有同样问题。通常需要十数秒才能返回.
这种性能是用户不能忍受的，需要进行优化，找到问题所在。以下是当时的诊断及问题解决过程，添加了必要的说明，供大家参考。
检查并跟踪数据库进程
由于发布系统是非实时系统，诊断时是晚上,基本无用户访问，选择在前台点击相关页面，同时进行后台进程跟踪。
查询v$session视图,获取进程信息：
SQL> select sid,serial#,username from v$session; SID SERIAL# USERNAME ---------- ---------- ------------------------------ 1 1 2 1 3 1 4 1 5 1 6 1 7 284 IFLOW 11 214 IFLOW 12 164 SYS 16 1042 IFLOW 10 rows selected.
除了SYS及后台进程外，其他3个进程是我们的诊断目标，对这几个进程启用相关进程sql_trace:
SQL> exec dbms_system.set_sql_trace_in_session(7,284,true) PL/SQL procedure successfully completed. SQL> exec dbms_system.set_sql_trace_in_session(11,214,true) PL/SQL procedure successfully completed. SQL> exec dbms_system.set_sql_trace_in_session(16,1042,true) PL/SQL procedure successfully completed.
此时在前台对相关页面进行刷新,等候一段时间,关闭sql_trace
SQL> exec dbms_system.set_sql_trace_in_session(7,284,false) PL/SQL procedure successfully completed. SQL> exec dbms_system.set_sql_trace_in_session(11,214,false) PL/SQL procedure successfully completed. SQL> exec dbms_system.set_sql_trace_in_session(16,1042,false) PL/SQL procedure successfully completed.
检查trace文件
在user_dump_dest目录下，我们可以找到生成的跟踪文件,然后通过Oracle提供的格式化工具-tkprof对trace文件进行格式化处理，检查发现以下语句是可疑的：
**************************************************************************** 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进行新闻内容读取的，auditstatus>0应该是限制只能读取审查过的内容。注意这里很可疑的是query读取有3892，按8k的block_size来计算的话，这大约是30M的逻辑读取。这个内容引起了我的注意。
如果遇到过类似的问题，大家在这里就应该可以大致猜到问题的原因了；如果没有遇到过的朋友，可以在这里思考一下再往下看。
这是Trace文件里的另外一段:
****************************************************************************
select auditstatus,categoryid
from
categoryarticleassign where articleId=20030700400138 and categoryId in ('63',
'138','139','140','141','142','143','144','168','213','292','341','346',
'347','348','349','350','351','352','353','354','355','356','357','358',
'359','360','361','362','363','364','365','366','367','368','369','370',
'371','372','383','460','461','462','463','621','622','626','629','631',
'634','636','643','802','837','838','849','850','851','852','853','854',
'858','859','860','861','862','863','-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
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 41
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL CATEGORYARTICLEASSIGN
****************************************************************************注意到，这里有一个全表扫描存在，对categoryarticleassign表的访问，最终是通过全表扫描完成的。
登陆数据库,检查相应索引及表结构
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
IDX_CAT_ARTICLE CATEGORYARTICLEASSIGN AUDITSTATUS
IDX_CAT_ARTICLE CATEGORYARTICLEASSIGN ARTICLEID
IDX_CAT_ARTICLE CATEGORYARTICLEASSIGN CATEGORYID
IDX_CAT_ARTICLE CATEGORYARTICLEASSIGN ASSIGNTYPE
11 rows selected.我们注意到,该表上ARTICLEID字段建有IDX_ARTICLEID索引，而该索引在以上查询中都没有被用到.接下来检查表结构:
SQL> desc categoryarticleassign Name Null? Type ----------------------------------------- -------- ---------------------------- CATEGORYID NOT NULL NUMBER ARTICLEID NOT NULL VARCHAR2(14) ASSIGNTYPE NOT NULL VARCHAR2(1) AUDITSTATUS NOT NULL NUMBER SORTID NOT NULL NUMBER UNPASS VARCHAR2(255)
问题发现:这里ARTICLEID是个字符型(VARCHAR2)数据，而在查询中给入的条件是
articleId= 20030700400141
在这个查询中, 20030700400141 被认为是一个数字值。Oracle在执行这个SQL时发生潜在的数据类型转换（把ARTICLEID转换为Number和20030700400141进行比较）,从而导致了索引失效。
我们在SQL*Plus中执行类似查询:
SQL> select auditstatus,categoryid 2 from 3 categoryarticleassign where articleId=20030700400132; AUDITSTATUS CATEGORYID ----------- ---------- 9 94 0 383 0 695 Elapsed: 00:00:02.62 Execution Plan ---------------------------------------------------------- 0 SELECT STATEMENT Optimizer=CHOOSE (Cost=110 Card=2 Bytes=38) 1 0 TABLE ACCESS (FULL) OF 'CATEGORYARTICLEASSIGN' (Cost=110 Card=2 Bytes=38)
发现执行的是全表扫描，索引被忽略，这显然不是我们想看到的。
解决方法
解决这个问题是简单的,在参数两侧各增加一个单引号（’）,既可解决这个问题。对于用单引号引起来的数字，Oracle会认为是字符串，这样就消除了隐式类型转换，索引得以被正确使用。
对于类似的查询,我们发现索引被正确使用，Query模式读取降低为2，执行该SQL几乎不需要花费CPU时间了
******************************************************************************* select unpass from categoryarticleassign where articleid='20030320000682' and categoryid='113' 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.00 0.00 0 2 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 0.00 0.00 0 2 0 0 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 20 Rows Row Source Operation ------- --------------------------------------------------- 0 TABLE ACCESS BY INDEX ROWID CATEGORYARTICLEASSIGN 1 INDEX RANGE SCAN (object id 3080) ********************************************************************************
至此，这个问题得到了完满的解决。
总结
在Oracle开发中，我们应该尽量避免使用隐式的数据类型转换，因为隐式数据类型转换可能会带来索引失效的问题，给系统埋下隐患。
这些问题，在开发阶段就应该被避免。使用显示的数据类型转换应该被作为规则确定下来。使用函数导致索引失效的问题与此类似。
我们在很多系统中看到，大量的性能问题都是由于简单的疏忽导致的，而且由于问题的隐蔽性等，这些问题一旦爆发出来，会给诊断优化带来相当的难度，所以完善的规范和良好的编码对于一个系统来说是至关重要的。
