20151111rman執行list backupset很慢的問題

[20151111]rman執行list backupset很慢的問題.txt

--我的測試環境在rman下執行list backupset很慢,這個問題由來已久,一直沒解決,以前我透過重新建立控制檔案來解決,不過沒多久有出
--現.今天做了1個10046跟蹤發現:

--以前遇到設定最佳化模式rule,或者執行exec dbms_stats.GATHER_FIXED_OBJECTS_STATS 都會好起來,但是我遇到的這些都不行.

1.問題提出:
SYS@test> @ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.3.0     Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

/* Formatted on 2015/11/11 11:44:58 (QP5 v5.252.13127.32867) */
DECLARE
   thread     NUMBER;
   sequence   NUMBER;
   recid      NUMBER;
   alRec      dbms_rcvman.alRec_t;
BEGIN
   dbms_rcvman.getArchivedLog (alRec => alRec);

   IF (    :rlscn = alRec.rlgSCN
       AND :stopthr = alRec.thread
       AND (   (alRec.sequence >= :stopseq AND :toclause = 0)
            OR (alRec.sequence > :stopseq AND :toclause = 1)))
   THEN
      :flag := 1;
   ELSE
      :flag := 0;
      :al_key:al_key_i := alRec.key;
      :recid:recid_i := alRec.recid;
      :stamp:stamp_i := alRec.stamp;
      :thread := alRec.thread;
      :sequence := alRec.sequence;
      :fileName:fileName_i := alRec.fileName;
      :lowSCN := alRec.lowSCN;
      :lowTime := alRec.lowTime;
      :nextSCN := alRec.nextSCN;
      :nextTime := NVL (alRec.nextTime, TO_DATE ('12/31/9999', 'MM/DD/YYYY'));
      :rlgSCN := alRec.rlgSCN;
      :rlgTime := alRec.rlgTime;
      :blocks := alRec.blocks;
      :blockSize := alRec.blockSize;
      :status := alRec.status;
      :compTime:compTime_i := alRec.compTime;
      :duplicate := alRec.duplicate;
      :compressed:compressed_i := alRec.compressed;
      :isrdf:isrdf_i := alRec.isrdf;
      :stby := alRec.stby;
      :terminal := alRec.terminal;
      :site_key:site_key_i := alRec.site_key;
      :source_dbid := alRec.source_dbid;
   END IF;
END;

--問題主要集中這條語句,不斷的迴圈執行.但是我觀察跟蹤檔案時不斷輸出如下內容,rman並沒有輸出.

Bind#27
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=01 fl2=1000000 frm=00 csi=00 siz=0 off=2600
  kxsbbbfp=2a97650d38  bln=22  avl=00  flg=01
FETCH #182927268104:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1395075536,tim=1447212896313250

$ grep -A5 "Bind#27" test_ora_20151_127_0_0_1.trc | grep FETCH | wc
    616    1232   61630

--也就是執行了616次.

SYS@test> select * from V$CONTROLFILE_RECORD_SECTION where records_used>=610;
TYPE                                     RECORD_SIZE RECORDS_TOTAL RECORDS_USED FIRST_INDEX LAST_INDEX LAST_RECID
---------------------------------------- ----------- ------------- ------------ ----------- ---------- ----------
ARCHIVED LOG                                     584           616          616         308        307       6159
DELETED OBJECT                                    20           818          818         223        222       4312

SYS@test> select count(*) FROM V$ARCHIVED_LOG;
  COUNT(*)
----------
       616
--很明顯問題是type='ARCHIVED LOG'的數量正好對上.

RMAN> list archivelog all ;

List of Archived Log Copies for database with db_unique_name TEST
=====================================================================

Key     Thrd Seq     S Low Time
------- ---- ------- - -------------------
6159    1    4012    A 2015-11-11 08:25:24
        Name: /u01/app/oracle11g/archivelog/1_4012_798551880.dbf

--僅僅看到1個,並且我這樣執行很快.透過tkprof觀察:

SQL ID: 7qd215rsryu1u Plan Hash: 0

declare thread   number; sequence number; recid    number; alRec
  dbms_rcvman.alRec_t; begin dbms_rcvman.getArchivedLog(alRec => alRec); if
  (:rlscn = alRec.rlgSCN and :stopthr = alRec.thread and ((alRec.sequence >=
  :stopseq and :toclause = 0) or (alRec.sequence > :stopseq and :toclause = 1)
  )) then :flag := 1; else :flag := 0; :al_key:al_key_i         := alRec.key;
  :recid:recid_i           := alRec.recid; :stamp:stamp_i           :=
  alRec.stamp; :thread                  := alRec.thread; :sequence
      := alRec.sequence; :fileName:fileName_i     := alRec.fileName; :lowSCN
                  := alRec.lowSCN; :lowTime                 := alRec.lowTime;
  :nextSCN                 := alRec.nextSCN; :nextTime                :=
  nvl(alRec.nextTime, to_date('12/31/9999', 'MM/DD/YYYY')); :rlgSCN
         := alRec.rlgSCN; :rlgTime                 := alRec.rlgTime; :blocks
                  := alRec.blocks; :blockSize               :=
  alRec.blockSize; :status                  := alRec.status;
  :compTime:compTime_i     := alRec.compTime; :duplicate               :=
  alRec.duplicate; :compressed:compressed_i := alRec.compressed;
  :isrdf:isrdf_i           := alRec.isrdf; :stby                    :=
  alRec.stby; :terminal                := alRec.terminal;
  :site_key:site_key_i     := alRec.site_key; :source_dbid             :=
  alRec.source_dbid; end if; end;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse      618      0.02       0.02          0          0          0           0
Execute    618      0.86       0.91          0          0          0         616
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     1236      0.88       0.94          0          0          0         616

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                     618        0.00          0.00
  SQL*Net message from client                   618        0.00          0.20
  SQL*Net break/reset to client                   4        0.00          0.00
********************************************************************************

--時間並不是很多.但是主要的等待就是在這裡.在這裡要迴圈616次才有輸出.

2.我這套系統為了學習dgmgrl,還建立dg,我在dg下測試rman的list backupset,顯示也很快出來:

SYS@testdg> select count(*) FROM V$ARCHIVED_LOG;
  COUNT(*)
----------
       308

--在主機上執行如下:
SYS@test> select * FROM V$ARCHIVED_LOG where name is null;
--303行.先不管問題在那裡,清除控制檔案的記錄資訊看看是否好轉.

3.清除控制檔案的記錄資訊:
--方法可以透過重建控制檔案的方法.還可以透過使用dbms_backup_restore包resetcfilesection可以清除對應的資訊.
--參考:http://blog.itpub.net/267265/viewspace-748366/

SYS@test>  execute dbms_backup_restore.resetcfilesection(11);
PL/SQL procedure successfully completed.

SYS@test> select * from (select rownum -1 a, crs.* from v$controlfile_record_section crs) where a=11;
         A TYPE                                     RECORD_SIZE RECORDS_TOTAL RECORDS_USED FIRST_INDEX LAST_INDEX LAST_RECID
---------- ---------------------------------------- ----------- ------------- ------------ ----------- ---------- ----------
        11 ARCHIVED LOG                                     584           616            0           0          0          0

--感覺是快了不少對比原來的情況,但是依舊感覺有點慢!大約3,5秒開始顯示.這樣估計問題還會再現,先這樣吧.
--註冊archive log檔案,再測試:

RMAN> catalog start with '/u01/app/oracle11g/archivelog/';

using target database control file instead of recovery catalog
searching for all files that match the pattern /u01/app/oracle11g/archivelog/

List of Files Unknown to the Database
=====================================
File Name: /u01/app/oracle11g/archivelog/1_4012_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4015_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4013_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4014_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4016_798551880.dbf

Do you really want to catalog the above files (enter YES or NO)? yes
cataloging files...
cataloging done

List of Cataloged Files
=======================
File Name: /u01/app/oracle11g/archivelog/1_4012_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4015_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4013_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4014_798551880.dbf
File Name: /u01/app/oracle11g/archivelog/1_4016_798551880.dbf

SYS@test> select * from (select rownum -1 a, crs.* from v$controlfile_record_section crs) where a=11;
         A TYPE                                     RECORD_SIZE RECORDS_TOTAL RECORDS_USED FIRST_INDEX LAST_INDEX LAST_RECID
---------- ---------------------------------------- ----------- ------------- ------------ ----------- ---------- ----------
        11 ARCHIVED LOG                                     584           616            5           1          5          5

--繼續測試,依舊3-5秒再顯示,先暫時這樣不管它.總之比原來的好許多......而且這樣臨時解決比較簡單.