在Oracle10g中診斷效能問題

oracle_ace發表於2008-01-19

Oracle10g為我們提供了,診斷和跟蹤效能問題的絕佳方法。這些方法相比以前有了一些改進,新引入了9i中沒有的新檢視,比如
v$sess_time_model,v$session_wait_class,同時v$session檢視的功能更加強大了。現在就來學習一下。呵呵:)

比如我做個實驗造成一個鎖等待

sess 1:
*********

SQL> select sid from v$mystat where rownum = 1;

       SID
----------
       525

SQL> select * from t;

        ID NAME
---------- ----------
         1 A
         2 B
         3 C
         4 D
         5 E

SQL> update t set name='e' where id=5;

1 row updated.


sess 2:
*********
SQL> select sid from v$mystat where rownum = 1;

       SID
----------
       532

SQL> update t set name='EE' where id=5;

此時這個session 532被hang住了。


在另外一個session我們來trace這個事件:

sess3:
**********
在Oracle 10g中v$session檢視得到了極大的改進,引入了v$session_wait檢視的一些功能。同時新增加了blocking_session這個column,表示某個session正在阻塞別人, 而且我們還可以根據wait_class這個列來對等待類別進行過濾

SQL> select sid,username,
     event,
     blocking_session,
     seconds_in_wait,
     wait_time
     from v$session where state in ('WAITING')
     and wait_class != 'Idle';

       SID USERNAME
---------- ------------------------------
EVENT                                                            SECONDS_IN_WAIT
---------------------------------------------------------------- ---------------
 WAIT_TIME
----------
       532 SYS
enq: TX - row lock contention                                              71536
         0

sess1的sid是525,sess2的sid是532,那麼結果表明,sid 532被blocking_session 525給blocked住了,以一種TX事務鎖的方式block

也就是說SID 525會話正在等待一個表上的事務鎖的釋放,而這個鎖正由532會話(BLOCKING_SESSION)佔用。

現在我又想知道是那個SQL語句導致了這個鎖的佔用也就是說,525這個session在執行什麼SQL,hold住了我們的事務鎖,那麼我們可以通過連線V$SESSION和V$SQL這兩個檢視執行下面的查詢很容易地找到答案:

SQL> select sid, sql_text
     from v$session s, v$sql q
     where sid in (532,525)
     and (q.sql_id = s.sql_id or q.sql_id = s.prev_sql_id);

這裡我們用到了sql_id這是10g推出的一種唯一標識SQL語句的列,通過他我們可以唯一標識我們的sql

       SID
----------
SQL_TEXT
---------------------------------------------
       525
update t set name='e' where id=5

       532
update t set name='EE' where id=5

       532
select sid from v$mystat where rownum = 1

我們看到兩個會話都試圖更新同一行。除非會話525提交或回滾,否則會話532將一直等待這個鎖。
 
以上就是我們的會話等待的檢索方法。

在10g之後還提出了等待類的概念:
並且推出了新的檢視v$session_wait_class
我們來看一下session 532的等待類

SQL> select wait_class_id,wait_class,total_waits,time_waited
     from v$session_wait_class
     where sid=532;

WAIT_CLASS_ID WAIT_CLASS
------------- ---------------------
TOTAL_WAITS TIME_WAITED
----------- -----------
   4217450380 Application
      23863     6986631

   2723168908 Idle
          6       38227

   2000153315 Network
          6           0

還是繼續上面的測試,我們知道sid=532一直在等待sid=525的會話,在這個結果中,顯示了每個類中會話的等待事件的次數,還有等待的時間,我們看到application這一級別中,的等待次數是876,而time_waited時間是69866.31秒(原來的6986631單位是釐秒單位,百分之一秒).那麼這個時候我們還可以從application等待類中尋找引起等待的原因。

v$system_event檢視中我們可以獲得每種等待的出現次數。我們這裡的application的id為4217450380

SQL> select event,total_waits,time_waited
  2  from v$system_event e,v$event_name n
  3  where n.event_id=e.event_id
  4  and n.wait_class_id=4217450380;

EVENT                                                            TOTAL_WAITS
---------------------------------------------------------------- -----------
TIME_WAITED
-----------
enq: RO - fast object reuse                                               51
          1

enq: TX - row lock contention                                          23891
    6994835

SQL*Net break/reset to client                                             34
          0

我們可以看到在這個application等待類中鎖的爭用佔了大部分的時間。

假如我們並不知道是什麼原因,導致了這個鎖的爭用,那我們該怎麼去定位這個TX-row lock contention的問題呢?這些資料僅僅告訴了我們ok,使用者經歷了23891次的鎖的競爭,共花費了6994835釐秒,有可能大多數的等待只有1到2釐秒,那麼如何在進行進一步的診斷呢?

Oracle 10g還為我們提供了另外一個檢視叫v$event_histogram
它標市了等待時間的週期以及會話等待某一特定時間週期的頻度

select wait_time_milli,wait_count
from v$event_histogram
where event='enq: TX - row lock contention';

WAIT_TIME_MILLI WAIT_COUNT
--------------- ----------
              1          0
              2          0
              4          0
              8          0
             16          0
             32          0
             64          0
            128          0
            256          4
            512         13
           1024          0
           2048          0
           4096      23896

v$event_histogram檢視顯示等待時間段以及在這期間會話等待某一特定事件--在這個例子中就是事務鎖爭用--的次數。例如,會話等待少於4096毫秒(ms)的事件共23532次,等等。WAIT_COUNT列值之和為23904.v$event_histogram檢視顯示,大多數等待發生在256毫秒、512毫秒和4096毫秒的事件上,這就充分證明了該應用程式正在經歷鎖的爭用問題,如果檢視顯示等待發生在1毫秒的範圍內,我們就不應該認為這是鎖爭用的問題,因為這樣短時間的等待似乎是正常的。

Oracle 10g還推出了一種時間模型的概念:

比如我們經常會遇到有人抱怨某某sid的會話非常的慢.這個時候,我們首先可以通過v$session來檢視。
首先我們可以監控出當前的活動session
SQL> select sid,username,status from v$session
     where status='ACTIVE' and username is not null;

       SID USERNAME                       STATUS
---------- ------------------------------ --------
       526 SYS                            ACTIVE
       532 SYS                            ACTIVE
       538 IRMADMIN                       ACTIVE

那麼我的業務session就是536了,通過 v$session檢視檢視

select event,seconds_in_wait,wait_time
from v$session
where sid= 538

EVENT                                                            SECONDS_IN_WAIT
---------------------------------------------------------------- ---------------
 WAIT_TIME
----------
db file sequential read                                                        0
         1

我們看到sid=538有個等待事件,這樣我們再來通過v$sess_time_model來估量一下,這個會話對資源的利用是否格外的高
SQL> select stat_name,value
  2  from v$sess_time_model
  3  where sid=538;

注意這些單位都是微秒一級的(1/1000000)
STAT_NAME                                                             VALUE
---------------------------------------------------------------- ----------
DB time                                                          2950266754
DB CPU                                                           2766530454
background elapsed time                                                   0
background cpu time                                                       0
sequence load elapsed time                                             8898
parse time elapsed                                                 32700260
hard parse elapsed time                                            31590611
sql execute elapsed time                                         2908768149
connection management call elapsed time                                2428
failed parse elapsed time                                                 0
failed parse (out of shared memory) elapsed time                          0
hard parse (sharing criteria) elapsed time                            63296
hard parse (bind mismatch) elapsed time                               63296
PL/SQL execution elapsed time                                      24049473
inbound PL/SQL rpc elapsed time                                           0
PL/SQL compilation elapsed time                                    21250121
Java execution elapsed time                                          902194
repeated bind elapsed time                                            18060
RMAN cpu time (backup/restore)                                            0

那麼在檢查資料庫效能的時候,有的時候我們還需要檢查作業系統一級的狀態,那麼在Oracle 10g之前呢,作業系統的工具比如OS,vmstat等工具,通過他們來確定一些爭用問題的度量指標,在Oracle 10g中,我們可以在資料庫中自動採集OS級別的度量指標,可以檢視主機的一些潛在的主機爭用問題

SQL> select stat_name,value from v$osstat;

這些單位都是釐秒一級的(1/100)

STAT_NAME                                                             VALUE
---------------------------------------------------------------- ----------
NUM_CPUS                                                                  4
IDLE_TIME                                                          34370136
BUSY_TIME                                                           1427854
USER_TIME                                                           1349492
SYS_TIME                                                              78323
IOWAIT_TIME                                                          209146
AVG_IDLE_TIME                                                       8591041
AVG_BUSY_TIME                                                        355613
AVG_USER_TIME                                                        336469
AVG_SYS_TIME                                                          18334
AVG_IOWAIT_TIME                                                       50465
OS_CPU_WAIT_TIME                                                    1446100
RSRC_MGR_CPU_WAIT_TIME                                                    0
LOAD                                                             .005859375
NUM_CPU_CORES                                                             2
NUM_VCPUS                                                                 2
NUM_LCPUS                                                                 4
PHYSICAL_MEMORY_BYTES                                            4026531840

系統的一個CPU有34370136釐秒空閒(IDLE_TIME)、1427854釐秒繁忙(BUSY_TIME),這表明CPU有大約4%的時間繁忙。可以得出結論,在主機中CPU不是瓶頸。請注意,如果主機系統有多於1個的CPU,則標頭中有AVG_字首的列,如AVG_IDLE_TIME將顯示所有CPU的這些度量指標的平均值。

有一種情況,當我們查詢v$session檢視的時候,會話是空閒的,可能沒有正在等待的事件,那麼我們如何來診斷這個會話 出現問題的時候是在等待什麼會話呢?

Oracle 10g在記憶體的緩衝區中每秒採集一次我們活動會話的資訊,這個緩衝區被稱為活動會話歷史(Active session history,ASH),我們可以在v$active_session_history這樣一個動態效能檢視中檢視他,其中的資料可以保留30分鐘,那麼我們在得到了sid和serial#後就可以查詢v$active_session_history來找到我們會話過去的等待事件。

SQL> select sample_time,event,wait_time
  2  from v$active_session_history
  3  where session_id=538 and session_serial#=11197 and event is not null;

SAMPLE_TIME
---------------------------------------------------------------------------
EVENT                                                             WAIT_TIME
---------------------------------------------------------------- ----------
19-JAN-08 12.46.42.757 PM
direct path read temp                                                     0

19-JAN-08 12.46.23.746 PM
db file sequential read                                                   0

19-JAN-08 12.46.22.745 PM
db file sequential read                                                   0

這樣我們就跟蹤出歷史的等待事件資訊:
通過聯合查詢v$sql檢視我們可以檢視到具體時間等待事件的sql語句:
 這裡我們檢視direct path read temp等待事件的sql資訊
select sql_text ,application_wait_time
from v$sql
where sql_id in
(select sql_id from v$active_session_history
where sample_time='19-JAN-08 12.46.42.757 PM' and session_id=538
and session_serial#=11197);

那麼其中application_wait_time表示執行這個SQL的會話等待了多長時間的application的等待類。

如果ash的內容30分鐘後被清除了,那麼這些資料並沒有丟失而是送到了AWR這樣一個工作負載庫中去了。這個庫的內容可以從dba_hist_active_session_hist中看到。在預設的情況下這個檢視的內容也只保留7天。

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

相關文章