link:
http://www.eygle.com/case/sql_trace_1.htm
問題描述:
這是幫助一個(gè)公司的診斷案例.
應(yīng)用是一個(gè)后臺(tái)新聞發(fā)布系統(tǒng).
癥狀是,通過連接訪問新聞頁是極其緩慢
通常需要十?dāng)?shù)秒才能返回.
這種性能是用戶不能忍受的.
操作系統(tǒng):SunOS 5.8
數(shù)據(jù)庫版本:8.1.7
1.檢查并跟蹤數(shù)據(jù)庫進(jìn)程
診斷時(shí)是晚上,無用戶訪問
在前臺(tái)點(diǎn)擊相關(guān)頁面,同時(shí)進(jìn)行進(jìn)程跟蹤
查詢v$session視圖,獲取進(jìn)程信息
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 IFLOW10 rows selected.
啟用相關(guān)進(jìn)程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 IFLOW10 rows selected.
等候一段時(shí)間,關(guān)閉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文件
檢查發(fā)現(xiàn)以下語句是可疑的
********************************************************************************select auditstatus,categoryid,auditlevel from categoryarticleassign a,category b where b.id=a.categoryid and articleId= 20030700400141 and auditstatus>0call count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 1 0.81 0.81 0 3892 0 1------- ------ -------- ---------- ---------- ---------- ---------- ----------total 3 0.81 0.81 0 3892 0 1********************************************************************************
這里顯然是根據(jù)articleId進(jìn)行新聞讀取的.
很可疑的是query讀取有3892
這個(gè)內(nèi)容引起了我的注重.
假如碰到過類似的問題，大家在這里就應(yīng)該知道是怎么回事情了.
假如沒有碰到過的朋友，可以在這里思考一下再往下看.
Misses in library cache during parse: 1Optimizer goal: CHOOSEParsing 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 0Execute 1 0.00 0.00 0 0 0 0Fetch 1 4.91 4.91 0 2835 7 1------- ------ -------- ---------- ---------- ---------- ---------- ----------total 3 4.91 4.91 0 2835 7 1Misses in library cache during parse: 1Optimizer goal: CHOOSEParsing user id: 41 Rows Row Source Operation------- --------------------------------------------------- 1 'TABLE ACCESS FULL CATEGORYARTICLEASSIGN'我們注重到，這里有一個(gè)全表掃描存在********************************************************************************
3.登陸數(shù)據(jù)庫,檢查相應(yīng)表結(jié)構(gòu)
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 ARTICLEIDIND_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索引在以上查詢中都沒有被用到.
檢查表結(jié)構(gòu):
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)
問題發(fā)現(xiàn):
因?yàn)锳RTICLEID是個(gè)字符型數(shù)據(jù),查詢中給入的articleId= 20030700400141 是一個(gè)數(shù)字值
Oracle發(fā)生潛在的數(shù)據(jù)類型轉(zhuǎn)換,從而導(dǎo)致了索引失效
SQL> select auditstatus,categoryid 2 from 3 categoryarticleassign where articleId=20030700400132;AUDITSTATUS CATEGORYID ----------- ---------- 9 94 0 383 0 695 Elapsed: 00:00:02.62Execution 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.解決方法
簡單的在參數(shù)兩側(cè)各增加一個(gè)',既可解決這個(gè)問題.
對(duì)于類似的查詢,我們發(fā)現(xiàn)Query模式讀取降低為2
幾乎不需要花費(fèi)CPU時(shí)間了
********************************************************************************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 0Execute 1 0.00 0.00 0 0 0 0Fetch 1 0.00 0.00 0 2 0 0------- ------ -------- ---------- ---------- ---------- ---------- ----------total 3 0.00 0.00 0 2 0 0Misses in library cache during parse: 1Optimizer goal: CHOOSEParsing user id: 20 Rows Row Source Operation------- --------------------------------------------------- 0 TABLE ACCESS BY INDEX ROWID CATEGORYARTICLEASSIGN 1 INDEX RANGE SCAN (object id 3080)********************************************************************************
至此,這個(gè)問題得到了完滿的解決.
