Oracle诊断案例-Sql_trace之一

s28bn5lc95

link:
http://www.eygle.com/case/sql_trace_1.htm
问题描述:
这是帮助一个公司的诊断案例.
应用是一个后台新闻发布系统.
症状是,通过连接访问新闻页是极其缓慢
通常需要十数秒才能返回.
这种性能是用户不能忍受的.
操作系统: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         1 ********************************************************************************

　　这里显然是根据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 ----------------------------------------- -------- ---------------------------- 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是个字符型数据,查询中给入的articleId= 20030700400141 是一个数字值
Oracle发生潜在的数据类型转换,从而导致了索引失效

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)

　　
4.解决方法

简单的在参数两侧各增加一个',既可解决这个问题.

对于类似的查询,我们发现Query模式读取降低为2
几乎不需要花费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) ********************************************************************************

至此,这个问题得到了完满的解决.