ORA-01555錯誤詳解

wuweilong發表於2012-05-15

ORA-01555錯誤詳解

ORA-01555(快照過舊)問題讓很多人感到十分頭痛。最近我們的生產系統上也報出了ORA-01555錯誤。就結合這次案例將ORA-1555問題作個案例分析,並淺析產生原因和各種解決辦法。

如果要了解1555錯誤產生的原因,就需要知道ORACLE的兩個特性:一致性讀(Consistent Get)和延遲塊清除(Delayed Block Cleanout)。此外,還要知道關於回滾段的一些配置引數。

相關引數

先看下Oracle中關於UNDO有哪些配置引數:

SQL> show parameter undo
NAME                  TYPE                 VALUE
--------------------- -------------------- -----------------------
undo_management       string               MANUAL
undo_retention        integer              900
undo_suppress_errors  boolean              FALSE
undo_tablespace       string               UNDOTBS1

undo_management

回滾段的管理方式。值可以為MANUAL/AUTO9i中預設是MANUAL10g中預設是AUTO

9i後,回滾段就以表空間的形式管理,並且支援系統自動管理回滾段。一個回滾表空間上可以建立多個回滾段,一個資料庫可以建立多個回滾表空間。但是,一個例項(Instance)只能使用一個回滾表空間。

如果undo_management設定為MANUAL,就是手動建立回滾段:

SQL> create rollback segment undo1 tablespace UNDOTBS1;

如果設定為AUTOOracle就自動管理回滾段的建立,而手工建立就會失敗。

undo_retention

這個引數設定回滾段中的被提交或回滾的資料強制保留時間,單位是秒。請注意,這個引數和1555錯誤有非常大的關係。但是,需要提醒的是,並不是回滾段中的資料超過這個時間以後就會被清除掉,而是等到後面事務產生的回滾資料覆蓋掉“超期”資料。所以這就是為什麼我們往往看到系統的回滾表空間佔有率始終是100%的原因了。

undo_suppress_errors

是否報與回滾段有關的錯誤。如果為FALSE,就不會產生與回滾段有關的錯誤。但是,請注意,並不是不會發生回滾段錯誤,而只是遮蔽錯誤資訊,錯誤發生了就會存在滴。在10g中,這個引數是隱含引數。

undo_tablespace

為每個例項制定的唯一當前使用的回滾段表空間。

一致性讀(ConsistentGet)

一致性讀(Consistent Get)可以說是產生1555錯誤的主要原因。但它的確是Oracle一個非常優秀的特性。既然這個特性會產生這麼煩人的錯誤,我為什麼還說它是ORACLE十分優秀的特性呢?下面就先了解一下這個特性:

併發事務和髒讀

需要先了解一下這一特性的產生的背景原因。看下以下這個例子。在一個銀行系統中(一般涉及到錢的問題對併發事務要求是最嚴格的^_^),會計正在統計當月某地區的個人存款總額,她的這個操作,在後臺肯定要產生一條SQL語句,對這一地區的所有使用者的存款額作SUM(),我們假設這一操作產生的語句為A,時間點是T1。由於存款使用者非常多,再加上會有一些對其他表的JOIN條件,語句A的執行時間可能比較長。這時,在A的執行過程中,A已經統計了賬戶X的錢,但還沒有統計到賬戶Y的錢的時候,正好有一個客戶透過ATM機從賬戶X中轉250元錢到帳戶Y,他的操作也產生了一條語句B,對存款表進行更新。開始時間點是T2,結束時間是T3。因為只更新兩條記錄,這個過程非常短。A結束時的時間點是T4。讓我們看下過程圖,看看會產生什麼結果:

從圖中,我們可以看到,T2時刻A已經統計過帳戶X中的錢,但在這時BX中轉了250元到帳戶Y中,在B結束的時刻T3A還沒有統計到Y,但Y已經多出了250元了,所以到T4,統計結束時,A實際上多統計出250元。這就是併發事務中的“髒讀(dirtyread)”問題。

在標準SQL中,為了防止併發事務中產生髒讀,就需要透過加鎖來控制。這樣就會帶來死鎖、阻塞的問題,即時是粒度最小的行級鎖,也無法避免這些問題。再看下上面這個例子。為了防止髒讀,A在開始時就需要對錶加鎖,防止其他事務更新表。這樣,B就會被阻塞,假如A事務要執行1個小時,B可能最長就要被阻塞1個小時(如果你是那個倒黴的客戶,可能早就***罵出來了)。再看下圖,

從圖中,可以看到,B開始時,存款表被加鎖了,所以BA阻塞,只有等A釋放鎖以後,B才能更新表。所以B被阻塞了很長時間。在大量併發事務系統中,可能會使整個系統慢得不可想象。

一致性讀

為了解決這一矛盾。Oracle充分利用的迴歸段,透過會滾段進行一致性讀取,即避免了髒讀,又大大減少了系統的阻塞、死鎖問題。下面就看下Oracle是如何實現一致性讀的:

Oracle更新資料塊(Data Block Oracle中最小的儲存單位)時,會在兩個地方記錄下這一更新動作。一個是重做段(Redo Segment),是用於資料庫恢復(Recover)用的。一個是回滾段(UNDO Segment),而回滾段是用於事務回滾(Rollback)的(我們只關心回滾段了)。並在資料塊頭部標示出來是否有修改資料。一個語句在讀取資料快時,如果發現這個資料塊是在它讀取的過程中被修改的(即開始執行讀操作時並沒有被修改),就不直接從資料塊上讀取資料,而是從相應的回滾段條目中讀取資料。這就保證了最終結果應該是讀操作開始時的那一時刻的快照(snapshot),而不會受到讀期間其他事務的影響。這就是Oracle的一致性讀,也可以叫做多版本(Multi-Versioning)。

以上面的例子為例,A在讀取到Y帳戶時,發現這條記錄已經被修改了,於是就從回滾段讀取保留的回滾資料,最終就能正確得到T1時刻的正確存款總額了。看下圖:

從圖上看出,A即能得出正確的資料,又保證B不會被阻塞。

延遲塊清除

再介紹一下另外一個可能產生1555錯誤的概念——延遲塊清除(Delayed Block Cleanout)。但個人認為,如果不從字面意思上翻譯,應該把它叫做延遲鎖清除更加讓人容易理解一些。

我們知道,當Oracle更新資料塊時,會在回滾段(UNDO Segment)記錄下這一更新動作。並且產生一個Cleanout SCN,在回滾段中,會產生對應的Transaction ID以及相應的資料記錄映象。並在對應的資料記錄上,產生鎖標誌。在事務提交(commit)前,會在資料塊的頭部記錄下這個Cleanout SCN(Csc)號、Undo BlockAddress(Uba)和Transaction ID(Xid);並且在在對應InterestedTransaction List(Itl)中設定鎖標誌,記錄這個事務在這資料塊中產生的鎖的數目;同時在對應修改的資料記錄上打上行級鎖標誌,並對映到對應的Itl去。當提交時,並不會一一清除掉所有鎖標誌,而是給對應的Itl打上相應標誌,告訴後面訪問該資料塊的事務,相應的事務已經提交。這就叫做快速提交(Fast Commit)。而後面訪問該資料塊的的事務就先檢查鎖標誌和對應的事務狀態,如果發現前面的事務沒有提交,並且要訪問的資料記錄被鎖住了,就被阻塞;否則就清除相應的鎖標誌,並提交自己的鎖標誌,再重複以上動作。這就事延遲塊清除。

而如果前面的事務在提交之前buffer cache中的髒資料已經被DBwn程式寫回,那麼Itl中的事務標誌就不會被更新,並且資料塊的Itl列表也不會記錄下事務的Commit SCN。後面的事務或查詢語句訪問該資料塊時,為了檢測是否需要進行一致性讀(如果資料塊的Itl中記錄的提交事務的Commit SCN大於當前訪問該資料塊的SCN,則需要進行一致性讀),就需要透過Undo Block AddressTransaction ID到回滾段的事務資訊表中去檢查前面事務的狀態和它的Commit SCN,確定是否做一致性讀,最後將前面事務在該資料塊上的標誌做一次Cleanout

下面就舉一個例子:

建立測試表:

SQL> create table t_multiver (a number, b number);
Table created.

插入測試資料,這時,實際上已經產生了一個對資料塊修改的事務:

SQL> insert into t_multiver values (1,1);
1 row created.
SQL> insert into t_multiver values (2,2);
1 row created.
SQL> insert into t_multiver values (3,3);
1 row created.
SQL>
SQL> commit;
Commit complete.

修改記錄,並且在commit之前將髒資料寫回:

SQL> conn demo/demo
Connected.
SQL> update t_multiver set b=115 where a=1;
1 row updated.
SQL> alter system flush buffer_cache;
System altered.
SQL> commit;
Commit complete.

Dump出資料塊:

SQL> alter system dump datafile 5 block 50959;
System altered.

看看Dump出來的內容:

Block header dump:  0x0140c70f
 Object id on Block? Y
 seg/obj: 0xe46c  csc: 0x00.a482a47c  itc: 2  flg: E  typ: 1 - DATA
     brn: 0  bdba: 0x140c709 ver: 0x01 opc: 0
     inc: 0  exflg: 0
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0012.02d.0000049c  0x02c00080.0192.0f  ----    1  fsc 0x0000.00000000
0x02   0x000f.01b.00000533  0x02c00054.01bb.0f  C---    0  scn 0x0000.a482a3c3
data_block_dump,data header at 0x7505664
===============
tsiz: 0x1f98
hsiz: 0x18
pbl: 0x07505664
bdba: 0x0140c70f
     76543210
flag=--------
ntab=1
nrow=3
frre=-1
fsbo=0x18
fseo=0x1f4a
avsp=0x1f62
tosp=0x1f62
0xe:pti[0] nrow=3   offs=0
0x12:pri[0]        offs=0x1f5e
0x14:pri[1]        offs=0x1f4a
0x16:pri[2]        offs=0x1f54
block_row_dump:
tab 0, row 0, @0x1f5e
tl: 10 fb: --H-FL-- lb: 0x1  cc: 2
col  0: [ 2]  c1 02
col  1: [ 3]  c2 02 10
tab 0, row 1, @0x1f4a
tl: 10 fb: --H-FL-- lb: 0x0  cc: 2
col  0: [ 2]  c1 03
col  1: [ 3]  c2 03 17
tab 0, row 2, @0x1f54
tl: 10 fb: --H-FL-- lb: 0x0  cc: 2
col  0: [ 2]  c1 04
col  1: [ 3]  c2 03 17
end_of_block_dump
End dump data blocks tsn: 5 file#: 5 minblk 50959 maxblk 50959

其餘的內容在我們討論的這個問題中不需要太關心,主要注意紅色黑體部分和InterestedTransaction Slot (ITS)部分。

CSC:Cleanout SCN,它是在我們的insert操作事務中產生的。

Flag事務標誌位。由於我們在提交之前將buffer cache手動flush了,所以標誌位為空。請注意到,我們這在commit之前DBwn已經寫回了髒資料,標誌為空。各個標誌的含義分別是:

C--- = transaction has beencommitted and locks cleaned out

-B-- = this undo recordcontains the undo for this ITL entry

--U- = transaction committed(maybe long ago); SCN is an upper bound
---T = transaction was still active at block cleanout SCN

可以看到,目前事務標誌是U,即事務已經提交,但是相應的鎖並沒有清除。所以,看到後面的Lck位(行級鎖數目)為1(因為我們修改了1條記錄)。

再看每條記錄中的行級鎖對應Itl條目lb:都是0x1。即Itl中的第一條。

這時,我們重新訪問該資料塊:

SQL> alter system flush buffer_cache;
System altered.
SQL> conn demo/demo
Connected.
SQL> select * from t_multiver;
         A          B
---------- ----------
         1        115
         2        222
         3        222
SQL> alter system dump datafile 5 block 50959;
System altered.

再將資料塊內容dump出來:

Block header dump:  0x0140c70f
 Object id on Block? Y
 seg/obj: 0xe46c  csc: 0x00.a482a4a3  itc: 2  flg: E  typ: 1 - DATA
     brn: 0  bdba: 0x140c709 ver: 0x01 opc: 0
     inc: 0  exflg: 0
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0012.02d.0000049c  0x02c00080.0192.0f  C---    0  scn 0x0000.a482a495
0x02   0x000f.01b.00000533  0x02c00054.01bb.0f  C---    0  scn 0x0000.a482a3c3
data_block_dump,data header at 0x7745664
===============
tsiz: 0x1f98
hsiz: 0x18
pbl: 0x07745664
bdba: 0x0140c70f
     76543210
flag=--------
ntab=1
nrow=3
frre=-1
fsbo=0x18
fseo=0x1f4a
avsp=0x1f62
tosp=0x1f62
0xe:pti[0] nrow=3   offs=0
0x12:pri[0]        offs=0x1f5e
0x14:pri[1]        offs=0x1f4a
0x16:pri[2]        offs=0x1f54
block_row_dump:
tab 0, row 0, @0x1f5e
tl: 10 fb: --H-FL-- lb: 0x0  cc: 2
col  0: [ 2]  c1 02
col  1: [ 3]  c2 02 10
tab 0, row 1, @0x1f4a
tl: 10 fb: --H-FL-- lb: 0x0  cc: 2
col  0: [ 2]  c1 03
col  1: [ 3]  c2 03 17
tab 0, row 2, @0x1f54
tl: 10 fb: --H-FL-- lb: 0x0  cc: 2
col  0: [ 2]  c1 04
col  1: [ 3]  c2 03 17
end_of_block_dump
End dump data blocks tsn: 5 file#: 5 minblk 50959 maxblk 50959

這時,可以看到,前一事務的Itl條目中,Flag標誌為已經被修改為C,即提交完畢,Commit SCN也被獲得。鎖也已經被清除,其鎖Lck的數量也清0。相應的,各條記錄的行鎖對應Itl位也被清0

還是圖解一下這個過程:

資料塊初始狀態:

第一個修改該資料塊的事務提交後:

第二個訪問該資料塊的事務(清除了相應鎖資訊)

當然,如果事務進行的刪除操作,或者事務回滾,又會有一些不同的情況。我的另外一篇文章中詳細的介紹了延遲塊清除這個東東。

1555錯誤的產生

透過分析Oracle的上面兩個特性,我們可以發現會存在這個情況,事務需要讀取回滾段已提交資料的資訊。這就是出問題的根本原因所在了:當這些資料超出了undo_retention設定的保留時間以後,是不會再被保護的,可能會被其他事務產生的回滾資料覆蓋掉。在一致性讀的情況下,再去讀取被清除的回滾資料資訊時,這個快照(snapshot)對於讀取者來說就太老了(too old)。在延遲塊清除的情況下,再讀取Cleanout SCN對應的回滾段事務表中的slot,也會報1555錯誤了。

此外,如果修改資料塊的事務時一個離散事務(discrete transaction, 透過executedbms_transaction.begin_discrete_transaction實現,是一種direct path方式的事務)、或者在使用sqlldr時指定direct=true時,將不會產生回滾資訊,也就是說查詢語句根本無法獲取到回滾資訊,因而也會產生1555錯誤

1555錯誤發生的情況

下面我們就模擬一下1555錯誤發生的情況。

測試環境

首先建立測試環境。由於我們只是要模擬1555錯誤的發生,所以需要建立一個小的回滾表空間,並且設定undo_retention時間為1(秒),以便回滾資料儘快被覆蓋(呵呵,要防止1555錯誤發生,這就一定要避免的)。

CREATE UNDO TABLESPACE rbs_ts

   DATAFILE 'rbs_ts2.dbf' SIZE 10M AUTOEXTEND OFF;



alter system set undo_retention=1 scope=spfile;
alter system set undo_management=auto scope=spfile;
alter system set undo_tablespace=rbs_ts scope=spfile;
startup force
alter tablespace rbs_ts online;
create table demo.t_dual as select * from dual;



insert into t_dual values(1);



commit;



一致性讀導致的1555錯誤

開始讀取表。

SQL>
SQL> var cl refcursor
SQL> begin
  2  open :cl for select * from demo.t_multiver;
  3  end;
  4  /
PL/SQL procedure successfully completed.
SQL>

更新表資料,產生回滾資訊。

SQL> update demo.t_multiver set b = 111 where a = 1;
1 row updated.
SQL> commit;
Commit complete.

執行大批其他事務,充滿所有回滾段,以致覆蓋上面的回滾資訊。回滾段可以透過dba_rollback_segs檢視。

SQL> begin
  2    for i in 1..20000 loop
  3      update demo.t_dual set dummy=1;
  4      commit;
  5    end loop;
  6  end;
  7
  8  /
PL/SQL procedure successfully completed.
SQL> /
PL/SQL procedure successfully completed.

查詢到更新過的資料記錄,回滾資訊已經被覆蓋,所以報1555錯誤。

SQL> print :cl
ERROR:
ORA-01555: snapshot too old: rollback segment number 18 with name "_SYSSMU18$"
too small
 
 
no rows selected
SQL>

延遲塊清除導致的1555錯誤

開始讀取表。

SQL> var cc refcursor
SQL>
SQL> begin
  2  open :cc for select * from t_multiver;
  3  end;
  4  /

這時一個事務更新了該資料塊,但在提交前,我們手工將buffer cache中的資料做了flush,再做提交。這時的資料塊上只記錄了鎖標誌,沒有事務標誌和Commit SCN

PL/SQL procedure successfully completed.
SQL>
SQL> update t_multiver set b=115 where a=1;
1 row updated.
SQL>
SQL> alter system flush buffer_cache;
System altered.
SQL>
SQL> commit;
Commit complete.

進行非常多的事務,將回滾段中的事務資訊表中的資料全部覆蓋:

SQL>
SQL> begin
  2    -- overwrite rollback slot
  3    for i in 1..40000 loop
  4      update t_dual set dummy=1;
  5      commit;
  6    end loop;
  7  end;
  8  /
PL/SQL procedure successfully completed.

讀取資料塊前需要到回滾段的事務資訊表中讀取Itl中沒有標記完全的事務的狀態和Commit SCN,以判斷是否需要進行一致性讀。但是事務資訊表中的資料都已經被覆蓋,所以報1555錯誤:

SQL>
SQL> print :cc
ERROR:
ORA-01555: snapshot too old: rollback segment number 20 with name "_SYSSMU20$"
too small
 
 
no rows selected

以上兩個例子看起來是好像很類似,但是,他們的本質區別是:第一個實際上是在進行一致性讀得時候發生的1555錯誤,而第二個例子是在判斷是否需要進行一致性讀得時候發生的1555錯誤。

解決1555錯誤的方法

現在,我們已經知道了1555錯誤產生的原因。那麼,就可以總結出以下方法來解決1555錯誤問題:

1、擴大回滾段

因為回滾段是迴圈使用的,如果回滾段足夠大,那麼那些被提交的資料資訊就能儲存足夠長的時間是那些大事務完成一致性讀取。

2、增加undo_retention時間

undo_retention規定的時間內,任何其他事務都不能覆蓋這些資料。

3、最佳化相關查詢語句,減少一致性讀。

減少查詢語句的一致性讀,就降低讀取不到回滾段資料的風險。這一點非常重要!

4、減少不必要的事務提交

提交的事務越少,產生的回滾段資訊就越少。

5、對大事務指定回滾段

透過以下語句可以指定事務的回滾段:

SET TRANSACTION USE ROLLBACK SEGMENT rollback_segment

給大事務指定回滾段,即降低大事務回滾資訊覆蓋其他事務的回滾資訊的機率,又降低了他自身的回滾資訊被覆蓋的機率。大事務的存在,往往是1555錯誤產生的誘因。

6、使用遊標時儘量使用顯式遊標,並且只在需要的時候開啟遊標,同時將所有可以在遊標外做的操作從遊標迴圈中拿出。

當遊標開啟時,查詢就開始了,直到遊標關閉。減少遊標的開啟時間,就減少了1555錯誤發生的機率。

下面例子中,第一段程式碼發生1555錯誤的機率就大於第二段的:

差的:

declare 

cursor cl is select b from demo.t_multiver;
v_b number;

begin

open cl; 



--do some thing without relation to the cursor.
fetch cl into v_b;

while cl%found loop
   --do other things without relation to the cursor.
  ... ...

  fetch cl into v_b;

end loop;
close cl; 



commit; 

END; 

好的:

declare 

cursor cl is select * from demo.t_multiver;

begin



--do some thing without relation to the cursor.
--do other things without relation to the cursor.
open cl; 

fetch cl into v_b;

while cl%found loop
  ... ...

  fetch cl into v_b;

end loop;
close cl; 



commit; 

END; 

7、使用回滾表空間自動管理

回滾表空間自動管理是9i後的特性。他由Oracle自動管理回滾段的建立和回收。儘管有人認為這一特性是以後犧牲效能為代價的,或者有其他缺點而不建議使用。但我認為,這確實是Oracle一個很好的特性,特別是OLTP環境下應該使用它。並且10g中,這一特性大大增強了。

而在大型的資料倉儲或者報表系統中,會有一些很大的查詢作業存在,這時可以考慮使用手動管理,為某些大作業建立單獨的回滾段。

以上總結了解決1555錯誤的各種辦法,具體採用哪種方式,就需要根據錯誤產生的實際情況來決定了。

例項分析

實際上,你在瞭解了1555錯誤為什麼會發生的前提,遇到了1555錯誤就不應該再手足無措了。但是,根據我個人的經驗,大多數的1555錯誤的發生,其根本原因還是語句寫得太爛,導致了大量的consistent gets和超長的執行時間,最後引發了1555錯誤。下面就是一個典型例子:

錯誤的發生

近來生產系統反饋,時常有作業被異常中止,導致應用程式被hung住。經過檢查日誌,是某個作業在執行時發生了1555錯誤,導致程式無法返回結果:

* 

ERROR at line 1: 

ORA-01555: snapshot too old: rollback segment number 9 with name "RBS08" too small 

ORA-06512: at "SQLUSER.EXT_PKG", line 4917 

ORA-06512: at line 1 

相關程式記錄下的日誌:

STAT-S.20060313185536.lg = 2 processed =20060313185536 end date Error = ORA-01555: snapshot too old: rollback segment number 9 with name "RBS08" too small BEGIN ext_pkg.main('extfiles','50','EAT'); END;

錯誤分析解決

這是一個典型的1555錯誤。檢查引發該錯誤的PACKAGE,發現它只有一個入口函式main(及程式日誌中記錄的函式),但這個函式還呼叫了其他NPACKAGE裡面的函式。這是一個大作業,執行時,設定它使用了一個大的回滾段:RBS_BATCH1

先看看相關配置:rollback tablespace空間為8G,undo_retention為1800。

看看回滾段的統計資料:

SQL> Select rn.Name "Rollback Segment", rs.RSSize/1024 "Size (KB)", rs.Gets "Gets",
  2         rs.waits "Waits", (rs.Waits/rs.Gets)*100 "% Waits",
  3         rs.Shrinks "# Shrinks", rs.Extends "# Extends"
  4  from   sys.v_$RollName rn, sys.v_$RollStat rs
  5  where  rn.usn = rs.usn;
Rollback Segment                Size (KB)       Gets      Waits    % Waits  # Shrinks  # Extends                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
------------------------------ ---------- ---------- ---------- ---------- ---------- ----------                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
SYSTEM                                952       1189          0          0          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
RBS_BATCH1                         409592     681422        667 .097883544          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
... ...S_BATCH1 getshould be provided by DEV Team.r.and CSS_EMAN_INDX exist.eir 
RBS10                              204792     478502         10 .002089855          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
RBS11                              204792     477366          8 .001675863          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
RBS12                              204792     491070          6 .001221822          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
RBS_BATCH2                         409592     650088        644 .099063511          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
RBS_BATCH3                         409592     243849          3  .00123027          0          0                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
 
16 rows selected.

注意到RBS_BATCHT1的wait%是0.098%,這個值應該是比較好的一個值。

回過頭再來看依法錯誤的語句:呼叫ext_pkg.main函式。在程式日誌中已經記錄下了輸入引數,這就比較好辦了:作一個trace,看看到底哪條語句的效能最差:

SQL> alter system set events ‘10046 trace name context forever, level 1’;
System altered.
SQL> exec ext_pkg.main('extfiles','50','EAT');
PL/SQL procedure successfully completed.
SQL> alter system set events ‘10046 trace name context off’;
System altered.

tkprof處理trace檔案後檢查trace檔案:

TKPROF: Release 9.2.0.5.0 - Production on Tue Mar 14 09:21:58 2006
Copyright (c) 1982, 2002, Oracle Corporation.  All rights reserved.
Trace file: prod_ora_29225.trc
Sort options: default
********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************
alter session set events='10046 trace name context forever, level 1'
... ...
BEGIN
ext_pkg.main('extfiles','50','EAT');
END;
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.04          4         39          0           0
Execute      1      0.20       0.21      24560      37808          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.21       0.26      24564      37847          0           1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 30
********************************************************************************
... ...
 
SELECT QID
FROM
 CSQUE QUE, ASTP STP WHERE
  QUE.CDE IN (:B3, :B2) AND QUE.TID =
  STP.TID AND STP.ACDE = :B1 ORDER BY
  QUE.CDE, QUE.DT
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch     2682      0.41       0.54       7557      10968          0        2680
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     2685      0.41       0.54       7557      10968          0        2680
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 31     (recursive depth: 1)
********************************************************************************
... ...
 
    7  user  SQL statements in session.
   41  internal SQL statements in session.
   48  SQL statements in session.
********************************************************************************
Trace file: prod_ora_29225.trc
Trace file compatibility: 9.02.00
Sort options: default
       1  session in tracefile.
       7  user  SQL statements in trace file.
      41  internal SQL statements in trace file.
      48  SQL statements in trace file.
      20  unique SQL statements in trace file.
    8626  lines in trace file.

trace檔案中,發現有一條語句效能相當差,透過對這條語句做SQL Trace,發現它的consistent gets達到80萬!

於是對該語句進行最佳化,調整了它的寫法,並建立了缺少的索引(最佳化過程略)。最終將consistent gets數量降低到了5000

重新安排上線,經過一週的觀察,1555錯誤沒再發生。

其實這個案例的解決是比較簡單的,最終的處理就是將一條語句進行最佳化。

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

相關文章