Oracle诊断案例4-Sql_trace

　　问题描述:
　　这是帮助一个公司的诊断案例.
　　
　　应用是一个后台新闻发布系统.
　　
　　症状是,通过连接访问新闻页是极其缓慢通常需要十数秒才能返回.
　　
　　这种性能是用户不能忍受的.
　　
　　操作系统:SunOS 5.8
　　数据库版本:8.1.7
　　　
　　1.检查并跟踪数据库进程
　　诊断时是晚上,无用户访问在前台点击相关页面,同时进行进程跟踪
　　
　　查询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.
　　
　　启用相关进程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> 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.
　　
　　等候一段时间,关闭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.
　　　
　　2.检查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　　　　&nb
　　
　　这里显然是根据articleId进行新闻读取的.很可疑的是query读取有3892
　　
　　这个内容引起了我的注意.
　　如果遇到过类似的问题，大家在这里就应该知道是怎么回事情了.如果没有遇到过的朋友，可以在这里思考一下再往下看.
　　
　　代码:
　　
　　Misses in library cache during parse: 1
　　
　　Optimizer goal: CHOOSE
　　
　　Parsing user id: 41　
　　
　　Rows　　 Row Source Operation
　　
　　-------　---------------------------------------------------
　　　　　1　NESTED LOOPS
　　　　　2　 INDEX RANGE SCAN (object id 25062)
　　　　　1　 TABLE ACCESS BY INDEX ROWID CATEGORY
　　　　　2　　INDEX 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')
　　
　　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'
　　
　　我们注意到，这里有一个全表扫描存在
　　
　　********************************************************************************
　　3.登陆数据库,检查相应表结构
　　代码:
　　
　　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.
　　
　　我们注意到,IDX_ARTICLEID索引在以上查询中都没有被用到.
　　
　　检查表结构:
　　
　　代码:
　　
　　SQL> desc categoryarticleassign
　　
　　 Name　　　　　　　　　　　　　　　　　　　Null?　　Type
　　
　　 ----------------------------------------- -------- ----------------------------
　　 CATEGORYI

查看本文来源