ITPub博客

首页 > Linux操作系统 > Linux操作系统 > Oracle11g物理STANDBY应用日志时进行增量备份导致10分钟等待

Oracle11g物理STANDBY应用日志时进行增量备份导致10分钟等待

原创 Linux操作系统 作者:yangtingkun 时间:2008-01-06 23:51:23 0 删除 编辑

又是一个特别长的标题。实在是没有办法,问题发生的条件和版本、是否STANDBY数据库、STANDBY数据库状态以及备份类型都有关系,不这样描述无法说清楚问题。

 

 

问题的发现是备份的时候等待时间很长,RMAN接受命令后等待了很长的时间也没有开始真正备份,等了10分钟左右备份才开始。从数据库中检查Oracle的等待事件为:control file sequential read

问题出现的时候情况比较复杂:数据库版本Oracle 11.1.0.6 for Enterprise Linux 5 for X86,部署了物理STANDBY环境。当前是在物理STANDBY数据库中测试BLOCK CHANGE TRACKING对增量备份的影响。STANDBY数据库的应用日志是开启的。而且数据库之前已经执行过不少复杂的造成,例如数据库启用日志的应用、关闭日志应用等。

上面的任何的一种或多种条件都可能是造成问题的原因,因此进行了大量的测试,每次只变动其中的一个条件,来检测问题是否存在,通过这种方式来定位问题的原因。

最后终于重现了这个问题:

[oracle@yangtk2 ~]$ sqlplus "/ as sysdba"

SQL*Plus: Release 11.1.0.6.0 - Production on Wed Dec 19 08:54:26 2007

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Connected to an idle instance.

SQL> startup mount
ORACLE instance started.

Total System Global Area  267825152 bytes
Fixed Size                  1299316 bytes
Variable Size             167775372 bytes
Database Buffers           96468992 bytes
Redo Buffers                2281472 bytes
Database mounted.
SQL> host
[oracle@yangtk2 ~]$ rman target /

Recovery Manager: Release 11.1.0.6.0 - Production on Wed Dec 19 08:54:57 2007

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

connected to target database: ORA11G (DBID=4026820313, not open)

RMAN> backup tablespace users;

Starting backup at 19-DEC-07
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=155 device type=DISK
channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/1uj3vsf6_1_1 tag=TAG20071219T085502 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> backup incremental level 0 tablespace users;

Starting backup at 19-DEC-07
using channel ORA_DISK_1
channel ORA_DISK_1: starting incremental level 0 datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/1vj3vsfi_1_1 tag=TAG20071219T085514 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> list backup;


List of Backup Sets
===================


BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
52      Full    8.23M      DISK        00:00:01     19-DEC-07     
        BP Key: 54   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T085502
        Piece Name: /data1/backup/1uj3vsf6_1_1
  List of Datafiles in backup set 52
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4       Full 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
53      Incr 0  8.23M      DISK        00:00:16     19-DEC-07     
        BP Key: 55   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T085514
        Piece Name: /data1/backup/1vj3vsfi_1_1
  List of Datafiles in backup set 53
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4    0  Incr 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

RMAN> delete noprompt backup;

using channel ORA_DISK_1

List of Backup Pieces
BP Key  BS Key  Pc# Cp# Status      Device Type Piece Name
------- ------- --- --- ----------- ----------- ----------
54      52      1   1   AVAILABLE   DISK        /data1/backup/1uj3vsf6_1_1
55      53      1   1   AVAILABLE   DISK        /data1/backup/1vj3vsfi_1_1
deleted backup piece
backup piece handle=/data1/backup/1uj3vsf6_1_1 RECID=54 STAMP=641724902
deleted backup piece
backup piece handle=/data1/backup/1vj3vsfi_1_1 RECID=55 STAMP=641724929
Deleted 2 objects


RMAN> exit


Recovery Manager complete.
[oracle@yangtk2 ~]$ exit
exit

SQL> alter database recover managed standby database disconnect from session;

Database altered.

SQL> host
[oracle@yangtk2 ~]$ rman target /

Recovery Manager: Release 11.1.0.6.0 - Production on Wed Dec 19 08:56:03 2007

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

connected to target database: ORA11G (DBID=4026820313, not open)

RMAN> backup tablespace users;

Starting backup at 19-DEC-07
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=140 device type=DISK
channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/20j3vsh9_1_1 tag=TAG20071219T085609 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> backup incremental level 0 tablespace users;

Starting backup at 19-DEC-07
using channel ORA_DISK_1

上面给出的测试是众多测试中比较有代表型的,选择了不同备份和增量备份不应用日志的情况下和应用日志情况下的对比。

在最后这种情况,STANDBY应用日志的时候执行增量备份,问题重现了。发出增量备份命令后,发生了等待现象。用sqlplus登陆数据库,检查等待事件:

SQL> SELECT SID, MODULE FROM V$SESSION WHERE USERNAME IS NOT NULL;

       SID MODULE
---------- ------------------------------------------------
       138 sqlplus@yangtk2.ytk-thinkpad (TNS V1-V3)
       140 backup incr datafile
       141 rman@yangtk2.ytk-thinkpad (TNS V1-V3)
       155 rman@yangtk2.ytk-thinkpad (TNS V1-V3)
       170 sqlplus@yangtk2.ytk-thinkpad (TNS V1-V3)

SQL> SELECT SID, EVENT, SECONDS_IN_WAIT FROM V$SESSION WHERE SID = 140;

       SID EVENT                                      SECONDS_IN_WAIT
---------- ------------------------------------------ ---------------
       140 control file sequential read                           375

SQL> SELECT SID, EVENT, SECONDS_IN_WAIT FROM V$SESSION WHERE SID = 140;

       SID EVENT                                      SECONDS_IN_WAIT
---------- ------------------------------------------ ---------------
       140 control file sequential read                           560

SQL> SELECT SID, EVENT, SECONDS_IN_WAIT FROM V$SESSION WHERE SID = 140;

       SID EVENT                                      SECONDS_IN_WAIT
---------- ------------------------------------------ ---------------
       140 SQL*Net message from client                             28

等待600秒后,等待事件结束,备份开始执行:

channel ORA_DISK_1: starting incremental level 0 datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/21j3vshk_1_1 tag=TAG20071219T085620 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> list backup;


List of Backup Sets
===================


BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
54      Full    8.23M      DISK        00:00:00     19-DEC-07     
        BP Key: 56   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T085609
        Piece Name: /data1/backup/20j3vsh9_1_1
  List of Datafiles in backup set 54
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4       Full 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
55      Incr 0  8.23M      DISK        00:10:01     19-DEC-07     
        BP Key: 57   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T085620
        Piece Name: /data1/backup/21j3vshk_1_1
  List of Datafiles in backup set 55
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4    0  Incr 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

从备份的执行时间Elapsed Time中也可以看到,RMAN在这里等待了10分钟,感觉这10分钟是一个超时阈值,超过10分钟后,等待超时,备份继续执行。

下面的测试发现,问题还与BLOCK CHANGE TRACKING有关:

RMAN> list backup;


List of Backup Sets
===================


BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
54      Full    8.23M      DISK        00:00:00     19-DEC-07     
        BP Key: 56   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T085609
        Piece Name: /data1/backup/20j3vsh9_1_1
  List of Datafiles in backup set 54
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4       Full 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
55      Incr 0  8.23M      DISK        00:10:01     19-DEC-07     
        BP Key: 57   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T085620
        Piece Name: /data1/backup/21j3vshk_1_1
  List of Datafiles in backup set 55
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4    0  Incr 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

RMAN> delete noprompt backup;

using channel ORA_DISK_1

List of Backup Pieces
BP Key  BS Key  Pc# Cp# Status      Device Type Piece Name
------- ------- --- --- ----------- ----------- ----------
56      54      1   1   AVAILABLE   DISK        /data1/backup/20j3vsh9_1_1
57      55      1   1   AVAILABLE   DISK        /data1/backup/21j3vshk_1_1
deleted backup piece
backup piece handle=/data1/backup/20j3vsh9_1_1 RECID=56 STAMP=641724969
deleted backup piece
backup piece handle=/data1/backup/21j3vshk_1_1 RECID=57 STAMP=641725580
Deleted 2 objects


RMAN> exit


Recovery Manager complete.
[oracle@yangtk2 ~]$ exit
exit

SQL> alter database disable block change tracking;

Database altered.

SQL> exit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
[oracle@yangtk2 ~]$ rman target /

Recovery Manager: Release 11.1.0.6.0 - Production on Wed Dec 19 10:12:37 2007

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

connected to target database: ORA11G (DBID=4026820313, not open)

RMAN> backup tablespace users;

Starting backup at 19-DEC-07
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=143 device type=DISK
channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/22j4010p_1_1 tag=TAG20071219T101241 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> backup cumulative incremental level 0 tablespace users;

Starting backup at 19-DEC-07
using channel ORA_DISK_1
channel ORA_DISK_1: starting incremental level 0 datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/23j4016g_1_1 tag=TAG20071219T101543 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> backup incremental level 0 tablespace users;

Starting backup at 19-DEC-07
using channel ORA_DISK_1
channel ORA_DISK_1: starting incremental level 0 datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/24j40178_1_1 tag=TAG20071219T101607 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> list backup;


List of Backup Sets
===================


BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
56      Full    8.23M      DISK        00:00:01     19-DEC-07     
        BP Key: 58   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T101241
        Piece Name: /data1/backup/22j4010p_1_1
  List of Datafiles in backup set 56
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4       Full 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
57      Incr 0  8.23M      DISK        00:00:15     19-DEC-07     
        BP Key: 59   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T101543
        Piece Name: /data1/backup/23j4016g_1_1
  List of Datafiles in backup set 57
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4    0  Incr 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
58      Incr 0  8.23M      DISK        00:00:15     19-DEC-07     
        BP Key: 60   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T101607
        Piece Name: /data1/backup/24j40178_1_1
  List of Datafiles in backup set 58
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4    0  Incr 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

再次ENABLE BLOCK CHANGE TRACKING,问题重现,看来问题和11G的物理STANDBYBLOCK CHANGE TRACKING特性有关。

[oracle@yangtk2 ~]$ sqlplus "/ as sysdba"

SQL*Plus: Release 11.1.0.6.0 - Production on Wed Dec 19 10:18:22 2007

Copyright (c) 1982, 2007, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> alter database enable block change tracking using file '/data1/track.trc';

Database altered.

SQL> exit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
[oracle@yangtk2 ~]$ rman target /

Recovery Manager: Release 11.1.0.6.0 - Production on Wed Dec 19 10:18:54 2007

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

connected to target database: ORA11G (DBID=4026820313, not open)

RMAN> backup tablespace users;

Starting backup at 19-DEC-07
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=155 device type=DISK
channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/25j401cl_1_1 tag=TAG20071219T101901 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> backup cumulative incremental level 0 tablespace users;

Starting backup at 19-DEC-07
using channel ORA_DISK_1
channel ORA_DISK_1: starting incremental level 0 datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00004 name=/data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf
channel ORA_DISK_1: starting piece 1 at 19-DEC-07
channel ORA_DISK_1: finished piece 1 at 19-DEC-07
piece handle=/data1/backup/26j401dc_1_1 tag=TAG20071219T101923 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 19-DEC-07

RMAN> list backup;


List of Backup Sets
===================


BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
59      Full    8.23M      DISK        00:00:00     19-DEC-07     
        BP Key: 61   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T101901
        Piece Name: /data1/backup/25j401cl_1_1
  List of Datafiles in backup set 59
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4       Full 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
60      Incr 0  8.23M      DISK        00:10:00     19-DEC-07     
        BP Key: 62   Status: AVAILABLE  Compressed: NO  Tag: TAG20071219T101923
        Piece Name: /data1/backup/26j401dc_1_1
  List of Datafiles in backup set 60
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  4    0  Incr 4748472    24-NOV-07 /data/oracle/oradata/ora11g/ORA11G_P/datafile/o1_mf_users_3d37bq45_.dbf

目前还没有在Metalink上发现这个问题的类似描述。

 

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/4227/viewspace-103786/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
暂无介绍

注册时间:2007-12-29

  • 博文量
    1955
  • 访问量
    10486290