link:http://www.eygle.com/case/sql_trace_1.htm問題描述:這是幫助一個公司的診斷案例.應用是一個后臺新聞發布系統.癥狀是,通過連接訪問新聞頁是極其緩慢通常需要十數秒才能返回. 這種性能是用戶不能忍受的.操作系統:SunOS 5.8數據庫版本:8.1.71.檢查并跟蹤數據庫進程 診斷時是晚上,無用戶訪問在前臺點擊相關頁面,同時進行進程跟蹤查詢v$session視圖,獲取進程信息SQL> select sid,serial#,username from v$session; SID SERIAL# USERNAME---------- ---------- ------------------------------ 11 21 31 41 51 61 7284 IFLOW11214 IFLOW12164 SYS16 1042 IFLOW10 rows selected. 啟用相關進程sql_traceSQL> 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---------- ---------- ------------------------------ 11 21 31 41 51 61 7284 IFLOW11214 IFLOW12164 SYS16 1042 IFLOW10 rows selected.等候一段時間,關閉sql_traceSQL> 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>0call count cpu elapsed disk query currentrows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse1 0.00 0.00000 0Execute 1 0.00 0.00000 0Fetch1 0.81 0.810 38920 1------- ------ -------- ---------- ---------- ---------- ---------- ----------total3 0.81 0.8103892 0 1******************************************************************************** 這里顯然是根據articleId進行新聞讀取的.很可疑的是query讀取有3892這個內容引起了我的注重.假如碰到過類似的問題，大家在這里就應該知道是怎么回事情了.假如沒有碰到過的朋友，可以在這里思考一下再往下看.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 currentrows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse1 0.00 0.00000 0Execute 1 0.00 0.00000 0Fetch1 4.91 4.910 28357 1------- ------ -------- ---------- ---------- ---------- ---------- ----------total3 4.91 4.910 28357 1Misses in library cache during parse: 1Optimizer goal: CHOOSEParsing 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_ARTICLEIDCATEGORYARTICLEASSIGNARTICLEIDIND_ARTICLEID_CATEGCATEGORYARTICLEASSIGNARTICLEID IND_ARTICLEID_CATEGCATEGORYARTICLEASSIGNCATEGORYIDIDX_SORTID CATEGORYARTICLEASSIGNSORTID PK_CATEGORYARTICLEASSIGN CATEGORYARTICLEASSIGNARTICLEID PK_CATEGORYARTICLEASSIGN CATEGORYARTICLEASSIGNCATEGORYIDPK_CATEGORYARTICLEASSIGN CATEGORYARTICLEASSIGNASSIGNTYPEIDX_CAT_ARTICLE CATEGORYARTICLEASSIGNAUDITSTATUS IDX_CAT_ARTICLE CATEGORYARTICLEASSIGNARTICLEID IDX_CAT_ARTICLE CATEGORYARTICLEASSIGNCATEGORYIDIDX_CAT_ARTICLE CATEGORYARTICLEASSIGNASSIGNTYPE11 rows selected. 我們注重到,IDX_ARTICLEID索引在以上查詢中都沒有被用到.檢查表結構:SQL> desc categoryarticleassign NameNull? 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 0383 0695 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.解決方法簡單的在參數兩側各增加一個',既可解決這個問題.對于類似的查詢,我們發現Query模式讀取降低為2幾乎不需要花費CPU時間了********************************************************************************select unpass from categoryarticleassign where articleid='20030320000682' and categoryid='113' call count cpu elapsed disk query currentrows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse1 0.00 0.00000 0Execute 1 0.00 0.00000 0Fetch1 0.00 0.00020 0------- ------ -------- ---------- ---------- ---------- ---------- ----------total3 0.00 0.00020 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)********************************************************************************至此,這個問題得到了完滿的解決.