【效能調整】等待事件(一)

yellowlee發表於2010-09-26

分析資料庫效能的一個很重要的指標就是分析資料庫中各種動作的執行時間和等待執行的時間。

前面提到過的幾個檢視,例如v$session_wait,v$session_event,v$system_event,提供了哪些資源正被等待的資訊,如果還設定了引數timed_statistics=true,則也有每種資源的等待時間的資訊。

(注:資料庫的各項時間統計資訊在設定了statistics_level=typical或者all的時候,會自動收集,如果這個蠶食設定為basic,那麼必須設定timed_statistics=true來允許收集時間資訊。

如果明確的設定下列引數或者使用alter session/system設定,那麼statistics_level也將會被覆蓋:

SQL> show parameter  DB_CACHE_ADVICE;

 

NAME                                 TYPE        VALUE

------------------------------------ ----------- ------------------------------

db_cache_advice                      string      ON

SQL> show parameter TIMED_STATISTICS;

 

NAME                                 TYPE        VALUE

------------------------------------ ----------- ------------------------------

timed_statistics                     boolean     TRUE

SQL> show parameter TIMED_OS_STATISTICS

 

NAME                                 TYPE        VALUE

------------------------------------ ----------- ------------------------------

timed_os_statistics                  integer     0

SQL>

v$session_wait 是一個當前狀態的檢視,列出了每個session當前wait或者上一次waitevent

v$session_event 列出的是每個sessionevent wait的歷史累計值,當一個session推出以後,這個session上的等待事件資訊將會從這個檢視中移除。

V$ssystem_event 列出系統所有等待的事件和時間,是從instance startup開始起的(也即所有的session wait 事件資料的總計)

因為v$session_wait是一個當前狀態檢視,因此包含了更細粒度的資訊,它包含了當前事件的一些屬性資料,列:P1,P2,P3

例如,v$session_event給出了某個session下有大量的db file scattered read event等待,但是並沒有給出是哪個file或者block號碼,但v$session_wait就給出了filenumber(P1)號,blocknumber(P2),block的數量。

v$event_name則是所有event的說明,包括了event#,每個eventp1,p2,p3欄位的解釋,等待的wait_class_id,wait_class#wait class說明(10g新增欄位)

10g開始還提供一些新的檢視,也提供等待的相關資訊:

V$system_wait_class

V$session_wait_class

V$session_wait_history

V$event_histogram

V$active_session_history

可以檢視按照wait的分類(10g)

SQL> select distinct wait_class#,wait_class from v$event_name a order by wait_class# ;

 

WAIT_CLASS# WAIT_CLASS

----------- ----------------------------------------------------------------

          0 Other

          1 Application

          2 Configuration

          3 Administrative

          4 Concurrency

          5 Commit

          6 Idle

          7 Network

          8 User I/O

          9 System I/O

         10 Scheduler

         11 Cluster

 

12 rows selected.

 

SQL> desc v$system_event

 Name                                      Null?    Type

 ----------------------------------------- -------- ----------------------------

 EVENT                                              VARCHAR2(64)

 TOTAL_WAITS                                        NUMBER

 TOTAL_TIMEOUTS                                     NUMBER              百分之一秒

 TIME_WAITED                                        NUMBER              百分之一秒

 AVERAGE_WAIT                                       NUMBER              百分之一秒

 TIME_WAITED_MICRO                                  NUMBER              9i開始(百萬分之一秒)

 EVENT_ID                                           NUMBER              10g

 WAIT_CLASS_ID                                      NUMBER              10g

 WAIT_CLASS#                                        NUMBER              10g

 WAIT_CLASS                                         VARCHAR2(64)        10g

其中total_waits包括了session在此事件上等待的次數,total_timeouts列記錄了session在初始的wait之後沒能獲得請求的資源的次數,time_waited是在event上花費的總時間,average_wait則是每次等待的平均時間: time_waited/total_waits

如果需要做個快速的系統效能check,可以檢視v$system_event,哪怕對系統或者應用並不完全熟悉。可以定位自資料庫例項啟動以來的top n瓶頸。

注意到:

1V$system_event檢視提供instance級別的wait event資訊。在這個級別上並不提供主要瓶頸發生的session資訊,並不能將檢視中某個很差的event與某個具體的session當前執行非常緩慢來關聯。

2,應該總是使用time_waited列來排序,而不是使用total_waited來排序,因為效能問題中絕對的時間大小總是關注的重點。當然,一些等待有很高的total_waits,而每個wait很短,比如latch free,這時候time_waited可能不是最重要的。而一些等待有很低的total_waits,但是每個等待的時間可能較長,比如enqueue(入隊)。

3,注意instance startup time,來評估wait time是否合理,不需要被很大的time_waited值嚇倒。

給出幾個sql

通常檢視v$system_event需要加上instancestartup_time

select a.*, b.startup_time

  from v$system_event a, v$instance b

 order by a.TIME_WAITED desc;

 

select c.WAIT_CLASS,

       c.name,

       a.TOTAL_WAITS,

       trunc(a.TOTAL_TIMEOUTS/100)||' S' TOTAL_TIMEOUTS_s,

       trunc(a.TIME_WAITED/100)||' S' time_waited_s,

       trunc(a.AVERAGE_WAIT/100)||' S' AVERAGE_WAIT,

       b.startup_time

  from v$system_event a, v$instance b, v$event_name c

 where a.EVENT = c.name

 order by a.TIME_WAITED desc;

注意到average_wait一列的相關events(user i/osystem i/o),這些指標能夠體現io子系統的速度,更重要的,它體現了系統的平均io cost。這意味著當有更高的io calls的時候,如果平均的io cost相對降低,那麼也是可以接受的。

SQL> select a.EVENT,a.TOTAL_WAITS,a.TIME_WAITED,a.AVERAGE_WAIT,a.WAIT_CLASS

  2   from v$system_event a where a.EVENT in

  3  ('db file sequential read','db file scattered read');

 

EVENT                                                            TOTAL_WAITS TIME_WAITED AVERAGE_WAIT WAIT_CLASS

---------------------------------------------------------------- ----------- ----------- ------------ -----------

db file sequential read                                                 8313        8347            1 User I/O

db file scattered read                                                  1249        1395         1.12 User I/O

可以看到系統的平均單塊讀和多塊讀的數量,1/100=10ms1.12/100=11.2ms

可以稍稍看看這個數字的變化,下面的測試使用的t_policy1萬條資料,且policy_id上有唯一索引,強制走索引,看看序列讀的相關值的變化:

SQL> set autot on

SQL> select /*+ use_nl(a,b) index(a pk_t_policy) */

  2   count(*)

  3    from test.t_policy a, test.t_policy b

  4   where a.policy_id = b.policy_id;

 

  COUNT(*)

----------

      9999

 

 

執行計劃

----------------------------------------------------------

Plan hash value: 2662632309

 

--------------------------------------------------------------------------------------

| Id  | Operation              | Name        | Rows  | Bytes | Cost (%CPU)| Time     |

--------------------------------------------------------------------------------------

|   0 | SELECT STATEMENT       |             |     1 |    12 | 53851  (50)| 00:10:47 |

|   1 |  SORT AGGREGATE        |             |     1 |    12 |            |          |

|   2 |   NESTED LOOPS         |             |  9964K|   114M| 53851  (50)| 00:10:47 |

|   3 |    INDEX FAST FULL SCAN| PK_T_POLICY |  9964K|    57M|  5077   (5)| 00:01:01 |

|*  4 |    INDEX UNIQUE SCAN   | PK_T_POLICY |     1 |     6 |     1   (0)| 00:00:01 |

--------------------------------------------------------------------------------------

 

Predicate Information (identified by operation id):

---------------------------------------------------

 

   4 - access("A"."POLICY_ID"="B"."POLICY_ID")

 

 

統計資訊

----------------------------------------------------------

          1  recursive calls

          0  db block gets

      10026  consistent gets

         17  physical reads

          0  redo size

        409  bytes sent via SQL*Net to client

        385  bytes received via SQL*Net from client

          2  SQL*Net roundtrips to/from client

          0  sorts (memory)

          0  sorts (disk)

          1  rows processed

 

SQL> select a.EVENT,a.TOTAL_WAITS,a.TIME_WAITED,a.AVERAGE_WAIT,a.WAIT_CLASS

  2   from v$system_event a where a.EVENT in

  3  ('db file sequential read','db file scattered read');

 

EVENT                                                            TOTAL_WAITS TIME_WAITED AVERAGE_WAIT WAIT_CLASS

---------------------------------------------------------------- ----------- ----------- ------------ -------------

db file sequential read                                                 8664        8524          .98 User I/O

db file scattered read                                                  1255        1398         1.11 User I/O

 

收集一下系統統計資訊:

begin

dbms_stats.gather_system_stats('start');

end;

/

再執行一下這個查詢:

select /*+ use_nl(a,b)  */

 *

  from test.t_policy a, test.t_policy b

 where a.policy_id = b.policy_id

;

使得a全表,b索引,執行完畢之後:

begin

dbms_stats.gather_system_stats('stop');

end;

/

SQL> select a.EVENT,a.TOTAL_WAITS,a.TIME_WAITED,a.AVERAGE_WAIT,a.WAIT_CLASS

  2   from v$system_event a where a.EVENT in

  3  ('db file sequential read','db file scattered read');

 

EVENT                                                            TOTAL_WAITS TIME_WAITED AVERAGE_WAIT WAIT_CLASS

---------------------------------------------------------------- ----------- ----------- ------------ -----------

db file sequential read                                                 8805        8548          .97 User I/O

db file scattered read                                                  1267        1405         1.11 User I/O

可以看到這個值仍然在下降。(注:這個測試之前,資料庫剛啟動)

檢視v$system_event的值是instance生命週期內的累計值,而且也不像v$log_history那樣記錄很多個不同時間的值,但是如果知道兩個時間點的一些值資訊,則可以判斷時間段內的大致的資料庫情況,這也是許多調優工具的原理,因此,我們也可以寫一些程式來抓取一些瞬時值為我們自己所用,或者寫一些job定期儲存系統檢視的資訊,供日常檢查和監控。(在分析調優工具的時候再詳述)

例如,假設兩次snap的值分別放在begin_system_eventend_system_event(實際上可以在同一個表標示snap_id),那麼這個差值很容易得到:

select t1.event,

       (t2.total_waits - nvl(t1.total_waits, 0)) "Delta_Waits",

       (t2.total_timeouts - nvl(t1.total_timeouts, 0)) "Delta_Timeouts",

       (t2.time_waited - nvl(t1.time_waited, 0)) "Delta_Time_Waited"

  from begin_system_event t1, end_system_event t2

 where t2.event = t1.event(+)

 order by (t2.time_waited - nvl(t1.time_waited, 0)) desc;

一些建立方法也可以在這裡找到:$ORACLE_HOME/rdbms/admin/ spctab.sql,而一些具體的分析方法後續詳述。

 

再來看看v$session_event

當已經知道某個sessionsid的時候,要分析這個session上的一些效能問題,這個檢視就非常適宜了,比如,某個使用者報說某個job或者過程跑的特別慢(通過username來找到相應的sid)。看看具體的欄位:

SQL> desc v$session_event

 名稱                                      是否為空? 型別

 ----------------------------------------- -------- -------------

 SID                                                NUMBER

 EVENT                                              VARCHAR2(64)

 TOTAL_WAITS                                        NUMBER

 TOTAL_TIMEOUTS                                     NUMBER

 TIME_WAITED                                        NUMBER

 AVERAGE_WAIT                                       NUMBER

 MAX_WAIT                                           NUMBER

 TIME_WAITED_MICRO                                  NUMBER

 EVENT_ID                                           NUMBER

 WAIT_CLASS_ID                                      NUMBER

 WAIT_CLASS#                                        NUMBER

 WAIT_CLASS                                         VARCHAR2(64)

(可以看到多出了sidmax_wait兩個欄位)

通過看time_waited值可以判斷一下是否有效能問題,並找出主要的瓶頸所在。

要注意的是:

通過這個檢視,也只能找到時哪類wait正在影響效能,而不能定位到是那個sql導致的,比如現在知道了db file scattered read在這個session上值很大,判斷很可能是全表掃描導致,這個時候就需要使用sid關聯v$session檢視,而v$session檢視中有sql_id,sql_address,sql_hash_value來和具體的sql對應,然後分析具體的sql來找出問題所在。

另外,單單用這個檢視也很難定位出問題的根源所在,只能說具體session下的某類問題可以大致判斷出來,比如,所有的latch waits都彙總到了latch free的等待事件,很難說哪一種latch wait是對當前session效能影響最大的。

可以看看當前系統中定義的latch等待事件:

select * from v$event_name  a where a.NAME like '%latch%';

不過10g中很少會有latches有大量的獨立等待事件,往往都是一起增加的。

另一個有用的欄位是max_wait,記錄著每個event每個session達到過的最大值,則很快可以發現這個sessionevent上發生過的最長的等待時間。使用dbms_system.kcfrms()可以將這個欄位清零。

 

V$session_wait

SQL>  desc v$session_wait

 名稱                                      是否為空? 型別

 ----------------------------------------- -------- --------------------

 SID                                                NUMBER

 SEQ#                                               NUMBER

 EVENT                                              VARCHAR2(64)

 P1TEXT                                             VARCHAR2(64)

 P1                                                 NUMBER

 P1RAW                                              RAW(4)

 P2TEXT                                             VARCHAR2(64)

 P2                                                 NUMBER

 P2RAW                                              RAW(4)

 P3TEXT                                             VARCHAR2(64)

 P3                                                 NUMBER

 P3RAW                                              RAW(4)

 WAIT_CLASS_ID                                      NUMBER

 WAIT_CLASS#                                        NUMBER

 WAIT_CLASS                                         VARCHAR2(64)

 WAIT_TIME                                          NUMBER

 SECONDS_IN_WAIT                                    NUMBER

 STATE                                              VARCHAR2(19)

 

P1,p2,p3三個欄位包含了事件的詳細資訊,不同的的event代表不同的意義。

當發現某個應用執行很慢的時候,可能需要去了解一下當前的會話都在做什麼事情,在什麼事件上花費了時間,可以使用這個檢視來看看一些瞬時值(多次查詢,如果這些值在不斷變化,或者週期性的變化,可能就意味著當前的應用目前是活動的,或正在工作;如果發現應用一直在等待相同的event,這個可能就意味著idle或者正在等待一些必須的資源,例如,鎖,latch,磁碟空間,或者某些resumeable會話)。

顯然,這個檢視只是在檢視當前的wait時非常有用,並不能體現過去某段時間的歷史值,要檢視會話的歷史值,可以檢視v$session_wait_history

當監控v$session_wait這個檢視的時候,尤其需要注意哪些state=WAITING的事件,這個表明session目前正在這個event上等待。

 

 

 

 

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/16179598/viewspace-674902/,如需轉載,請註明出處,否則將追究法律責任。

相關文章