[转载]Oracle诊断案例-Sql_trace之一(页 1) - 常用数据库类{ Database Security } - 巨人脚下[ Oracle ] - 邪恶八进制信息安全团队技术讨论组努力为祖国的信息安全撑起一片蓝天

pub!1c 2006-2-12 11:09

[转载]Oracle诊断案例-Sql_trace之一

信息来源:邪恶八进制信息安全团队
问题描述: 这是帮助一个公司的诊断案例. 应用是一个后台新闻发布系统. 症状是,通过连接访问新闻页是极其缓慢 通常需要十数秒才能返回. 这种性能是用户不能忍受的. 操作系统:SunOS 5.8 数据库版本:8.1.7

pub!1c 2006-2-12 11:10

1.检查并跟踪数据库进程 诊断时是晚上,无用户访问 在前台点击相关页面,同时进行进程跟踪 查询v$session视图,获取进程信息 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 SQL> select sid,serial#,username from v$session;
 
 SIDSERIAL# USERNAME
 ---------- ---------- ------------------------------
 11
 21
 31
 41
 51
 61
 7284 IFLOW
 11214 IFLOW
 12164 SYS
 161042 IFLOW
 
 10 rows selected. </CODE><HR></PRE></BLOCKQUOTE> 启用相关进程sql_trace 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 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> select sid,serial#,username from v$session;
 
 SIDSERIAL# USERNAME
 ---------- ---------- ------------------------------
 11
 21
 31
 41
 51
 61
 7284 IFLOW
 11214 IFLOW
 12164 SYS
 161042 IFLOW
 
 10 rows selected. </CODE><HR></PRE></BLOCKQUOTE> 等候一段时间,关闭sql_trace 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 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. </CODE><HR></PRE></BLOCKQUOTE>

pub!1c 2006-2-12 11:10

2.检查trace文件 检查发现以下语句是可疑的 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 ********************************************************************************
 
 select auditstatus,categoryid,auditlevel
 from
 categoryarticleassign a,category b where b.id=a.categoryid and articleId=
 20030700400141 and auditstatus>0
 
 
 callcountcpuelapseddiskquerycurrentrows
 ------- -------------- ---------- ---------- ---------- --------------------
 Parse10.000.000000
 Execute10.000.000000
 Fetch10.810.810389201
 ------- -------------- ---------- ---------- ---------- --------------------
 total30.810.810'3892'0&nb</CODE><HR></PRE></BLOCKQUOTE> 这里显然是根据articleId进行新闻读取的. 很可疑的是query读取有3892 这个内容引起了我的注意. 如果遇到过类似的问题，大家在这里就应该知道是怎么回事情了. 如果没有遇到过的朋友，可以在这里思考一下再往下看. 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 Misses in library cache during parse: 1
 Optimizer goal: CHOOSE
 Parsing user id: 41
 
 RowsRow Source Operation
 ----------------------------------------------------------
 1NESTED LOOPS
 2INDEX RANGE SCAN (object id 25062)
 1TABLE ACCESS BY INDEX ROWID CATEGORY
 2INDEX UNIQUE SCAN (object id 25057)
 
 ********************************************************************************
 
 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')
 
 
 callcountcpuelapseddiskquerycurrentrows
 ------- -------------- ---------- ---------- ---------- --------------------
 Parse10.000.000000
 Execute10.000.000000
 Fetch14.914.910283571
 ------- -------------- ---------- ---------- ---------- --------------------
 total34.914.910283571
 
 Misses in library cache during parse: 1
 Optimizer goal: CHOOSE
 Parsing user id: 41
 
 RowsRow Source Operation
 ----------------------------------------------------------
 1 'TABLE ACCESS FULL CATEGORYARTICLEASSIGN'
 
 我们注意到，这里有一个全表扫描存在
 
 
 ******************************************************************************** </CODE><HR></PRE></BLOCKQUOTE>

pub!1c 2006-2-12 11:10

3.登陆数据库,检查相应表结构 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 SQL> select index_name,table_name,column_name from user_ind_columns
 2where table_name=upper('categoryarticleassign');
 
 INDEX_NAMETABLE_NAMECOLUMN_NAME
 ------------------------------ ------------------------------ --------------------
 'IDX_ARTICLEIDCATEGORYARTICLEASSIGNARTICLEID'
 IND_ARTICLEID_CATEGCATEGORYARTICLEASSIGNARTICLEID
 IND_ARTICLEID_CATEGCATEGORYARTICLEASSIGNCATEGORYID
 IDX_SORTIDCATEGORYARTICLEASSIGNSORTID
 PK_CATEGORYARTICLEASSIGNCATEGORYARTICLEASSIGNARTICLEID
 PK_CATEGORYARTICLEASSIGNCATEGORYARTICLEASSIGNCATEGORYID
 PK_CATEGORYARTICLEASSIGNCATEGORYARTICLEASSIGNASSIGNTYPE
 IDX_CAT_ARTICLECATEGORYARTICLEASSIGNAUDITSTATUS
 IDX_CAT_ARTICLECATEGORYARTICLEASSIGNARTICLEID
 IDX_CAT_ARTICLECATEGORYARTICLEASSIGNCATEGORYID
 IDX_CAT_ARTICLECATEGORYARTICLEASSIGNASSIGNTYPE
 
 11 rows selected. </CODE><HR></PRE></BLOCKQUOTE> 我们注意到,IDX_ARTICLEID索引在以上查询中都没有被用到. 检查表结构: 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 SQL> desc categoryarticleassign
 NameNull?Type
 ----------------------------------------- -------- ----------------------------
 CATEGORYIDNOT NULL NUMBER
 'ARTICLEIDNOT NULL VARCHAR2(14)'
 ASSIGNTYPENOT NULL VARCHAR2(1)
 AUDITSTATUSNOT NULL NUMBER
 SORTIDNOT NULL NUMBER
 UNPASSVARCHAR2(255) </CODE><HR></PRE></BLOCKQUOTE> 问题发现: 因为ARTICLEID是个字符型数据,查询中给入的articleId= 20030700400141 是一个数字值 Oracle发生潜在的数据类型转换,从而导致了索引失效 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 SQL>select auditstatus,categoryid
 2from
 3categoryarticleassign where articleId=20030700400132;
 
 AUDITSTATUS CATEGORYID
 ----------- ----------
 994
 0383
 0695
 
 Elapsed: 00:00:02.62
 
 Execution Plan
 ----------------------------------------------------------
 0SELECT STATEMENT Optimizer=CHOOSE (Cost=110 Card=2 Bytes=38)
 10TABLE ACCESS (FULL) OF 'CATEGORYARTICLEASSIGN' (Cost=110 Card=2 Bytes=38) </CODE><HR></PRE></BLOCKQUOTE>

pub!1c 2006-2-12 11:10

4.解决方法 简单的在参数两侧各增加一个',既可解决这个问题. 对于类似的查询,我们发现Query模式读取降低为2 几乎不需要花费CPU时间了 
<BLOCKQUOTE><PRE>代码:<HR><CODE>
 ********************************************************************************
 
 select unpass
 from
 categoryarticleassign where articleid='20030320000682' and categoryid='113'
 
 callcountcpuelapseddiskquerycurrentrows
 ------- -------------- ---------- ---------- ---------- --------------------
 Parse10.000.000000
 Execute10.000.000000
 Fetch10.000.000200
 ------- -------------- ---------- ---------- ---------- --------------------
 total30.000.000200
 
 Misses in library cache during parse: 1
 Optimizer goal: CHOOSE
 Parsing user id: 20
 
 RowsRow Source Operation
 ----------------------------------------------------------
 0TABLE ACCESS BY INDEX ROWID CATEGORYARTICLEASSIGN
 1INDEX RANGE SCAN (object id 3080)
 
 ******************************************************************************** </CODE><HR></PRE></BLOCKQUOTE> 至此,这个问题得到了完满的解决.

pub!1c 2006-2-12 11:12

总结 在Oracle开发中,我们应该尽量避免使用隐式的数据类型转换 因为隐式数据类型转换可能会带来索引失效的问题. 这些问题，在开发阶段就应该被避免. 使用函数导致索引失效的问题与此类似. 本例给出了一个诊断问题的方法,供大家商榷参考. -Eygle

页: [1]

邪恶八进制信息安全团队技术讨论组's Archiver

[转载]Oracle诊断案例-Sql_trace之一