ORA-01196/ORA-01110特殊恢复案例一则

前不久,我们一套生产数据库的dataguard的备库出现实时应用过慢,数据库服务器IOWAIT高的情况,为了避免主库归档日志出现大量挤压,所以值班同事临时应急将主备库关系配置断掉,后续再进行DataGuard重构。除此之外,我们准备将备库打开进行一系列测试,试图探寻数据库服务器IOWAIT高的原因并解决DataGuard延迟的问题。

第二天,同事尝试打开备库,但是报了ORA-01196与错误

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-10458: standby database requires recovery
ORA-01196: file 1 is inconsistent due to a failed media recovery session
ORA-01110: data file 1: '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf'

此错误因为备库还未将redo log与archive恢复至一致状态,数据库此时处于不一致状态是无法打开的。但是,备库所有的归档日志已经被删除,此时数据库无法进行一个完全恢复

SQL> set line 1000 pagesize 200
SQL> select name,open_mode,CONTROLFILE_CHANGE#,CHECKPOINT_CHANGE#,CURRENT_SCN,DATABASE_ROLE from V$database;

NAME      OPEN_MODE            CONTROLFILE_CHANGE# CHECKPOINT_CHANGE# CURRENT_SCN DATABASE_ROLE
--------- -------------------- ------------------- ------------------ ----------- ----------------
Travelskydba  MOUNTED                          7669047             966955     7669046 PHYSICAL STANDBY

SQL>  ALTER DATABASE ACTIVATE STANDBY DATABASE;
 ALTER DATABASE ACTIVATE STANDBY DATABASE
*
ERROR at line 1:
ORA-01196: file 1 is inconsistent due to a failed media recovery session
ORA-01110: data file 1: '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf'

此时,我准备重建控制文件,进行不完全恢复操作

QL> alter database backup controlfile to trace as '/home/ora11g/albert.ctl';

Database altered.

SQL> shutdown immediate;
ORA-01109: database not open


Database dismounted.
ORACLE instance shut down.
SQL> 

albert.ctl文件内容:
STARTUP NOMOUNT
CREATE CONTROLFILE REUSE DATABASE "ORA1459T" RESETLOGS  ARCHIVELOG
    MAXLOGFILES 16
    MAXLOGMEMBERS 3
    MAXDATAFILES 100
    MAXINSTANCES 8
    MAXLOGHISTORY 292
LOGFILE
  GROUP 1 (
    '/oracle/redo_Travelskydba1/Travelskydba_DG/redo11.log',
    '/oracle/redo_Travelskydba1/Travelskydba_DG/redo12.log'
  ) SIZE 300M BLOCKSIZE 512,
  GROUP 2 (
    '/oracle/redo_Travelskydba1/Travelskydba_DG/redo21.log',
    '/oracle/redo_Travelskydba1/Travelskydba_DG/redo22.log'
  ) SIZE 300M BLOCKSIZE 512,
  GROUP 3 (
    '/oracle/redo_Travelskydba1/Travelskydba_DG/redo31.log',
    '/oracle/redo_Travelskydba1/Travelskydba_DG/redo32.log'
  ) SIZE 300M BLOCKSIZE 512
-- STANDBY LOGFILE
--   GROUP 4 '/oracle/redo_Travelskydba1/Travelskydba_DG/standby_redo04.log'  SIZE 300M BLOCKSIZE 512,
--   GROUP 5 '/oracle/redo_Travelskydba1/Travelskydba_DG/standby_redo05.log'  SIZE 300M BLOCKSIZE 512
DATAFILE
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf',
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/sysaux01.dbf',
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/undotbs01.dbf',
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/users01.dbf',
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/users02.dbf',
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/users03.dbf',
  '/oracle/oradata_Travelskydba1/Travelskydba_DG/users04.dbf'
CHARACTER SET AL32UTF8
;

[ora11g@ALBERT ~]$ !sql
sqlplus / as sysdba

SQL*Plus: Release 11.2.0.4.0 Production on Sat Mar 28 12:36:00 2020

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

Connected to an idle instance.

SQL> @albert.ctl
ORACLE instance started.

Total System Global Area 3290345472 bytes
Fixed Size                  2257720 bytes
Variable Size            1191185608 bytes
Database Buffers         2080374784 bytes
Redo Buffers               16527360 bytes

Control file created.  --控制文件重建完毕

SQL> recover database using backup controlfile until cancel;
ORA-00279: change 7669047 generated at 11/04/2019 23:00:11 needed for thread 1
ORA-00289: suggestion :
/oracle/oradata_Travelskydba1/Travelskydba_DG/1_247_1017488189.dbf
ORA-00280: change 7669047 for thread 1 is in sequence #247


Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
cancel
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01196: file 1 is inconsistent due to a failed media recovery session
ORA-01110: data file 1: '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf'


ORA-01112: media recovery not started

SQL> alter database open resetlogs;  --仍然无法打开数据库
alter database open resetlogs
*
ERROR at line 1:
ORA-01196: file 1 is inconsistent due to a failed media recovery session
ORA-01110: data file 1: '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf'

修改数据库alter system set “_allow_resetlogs_corruption” =true scope=spfile;参数,再次进行不完全恢复(此操作会有严重丢失数据风险,生产系统请慎用)

SQL> startup nomount;
ORACLE instance started.

Total System Global Area 3290345472 bytes
Fixed Size                  2257720 bytes
Variable Size            1191185608 bytes
Database Buffers         2080374784 bytes
Redo Buffers               16527360 bytes
SQL> alter system set "_allow_resetlogs_corruption" =true scope=spfile;

System altered.
SQL> shutdown abort;
ORACLE instance shut down.

SQL> @albert.ctl
ORACLE instance started.

Total System Global Area 3290345472 bytes
Fixed Size                  2257720 bytes
Variable Size            1191185608 bytes
Database Buffers         2080374784 bytes
Redo Buffers               16527360 bytes

Control file created.

SQL> recover database using backup controlfile until cancel;
ORA-00279: change 7669047 generated at 11/04/2019 23:00:11 needed for thread 1
ORA-00289: suggestion :
/oracle/oradata_Travelskydba1/Travelskydba_DG/1_247_1017488189.dbf
ORA-00280: change 7669047 for thread 1 is in sequence #247


Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
cancel
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01196: file 1 is inconsistent due to a failed media recovery session
ORA-01110: data file 1: '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf'


ORA-01112: media recovery not started


SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-00704: bootstrap process failure
ORA-00704: bootstrap process failure
ORA-00600: internal error code, arguments: [2662], [0], [7669055], [0],
[7996264], [4194545], [], [], [], [], [], []
Process ID: 12086
Session ID: 1705 Serial number: 3

此时出现ORA-00600 2262错误,此时距离成功已经不远,只需要推进SCN即可,
SQL> shutdown abort;
ORACLE instance shut down.
SQL> @albert.ctl
ORACLE instance started.

Total System Global Area 3290345472 bytes
Fixed Size                  2257720 bytes
Variable Size            1191185608 bytes
Database Buffers         2080374784 bytes
Redo Buffers               16527360 bytes

Control file created.

SQL> recover database using backup controlfile until cancel;
ORA-00279: change 7779049 generated at 03/28/2020 12:54:12 needed for thread 1
ORA-00289: suggestion : /oracle/oradata_Travelskydba1/Travelskydba_DG/1_2_1036241636.dbf
ORA-00280: change 7779049 for thread 1 is in sequence #2


Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
cancel
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01194: file 1 needs more recovery to be consistent
ORA-01110: data file 1: '/oracle/oradata_Travelskydba1/Travelskydba_DG/system01.dbf'


ORA-01112: media recovery not started


SQL> oradebug setmypid
Statement processed.
SQL> oradebug dumpvar sga kcsgscn_
kcslf kcsgscn_ [06001AE70, 06001AEA0) = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 6001AB50 00000000
SQL>  oradebug poke 0x06001AE70 4 8279047 
BEFORE: [06001AE70, 06001AE74) = 00000000
AFTER:  [06001AE70, 06001AE74) = 007E5407

SQL> alter database open resetlogs;  --数据库成功打开

Database altered.


SQL> set line 1000 pagesize 200    
SQL> select name,open_mode,CONTROLFILE_CHANGE#,CHECKPOINT_CHANGE#,CURRENT_SCN,DATABASE_ROLE from V$database;

NAME      OPEN_MODE            CONTROLFILE_CHANGE# CHECKPOINT_CHANGE# CURRENT_SCN DATABASE_ROLE
--------- -------------------- ------------------- ------------------ ----------- ----------------
Travelskydba  READ WRITE                       8280898            8279049     8280903 PRIMARY

主库 drop tablespace后备库存储空间不释放案例一则

上周,应用人员误操作在平台上tablespace name 打错名字,从而想删除表空间进行重新建立。重建后此数据库备库触发了文件系统满的报警,备库文件系统使用率已经为100%,但是数据库值班人员观察到备库之前建立错误的数据文件已经不在,为何文件系统存储中文件却没有删掉?之前怎么没有出现如此的情况?

我随后做了一个实验给他,原因是在drop tablespace时,没有加上including contents and datafiles

--主库:
SQL> select username,count(*) from gv$session group by username order by 2 desc;

USERNAME                         COUNT(*)
------------------------------ ----------
                                      174
ZABBIX                                  6
SYS                                     5
DBSNMP                                  4
PUBLIC                                  1

SQL> 
SQL> 
SQL> 
SQL> 
SQL> 
SQL> 
SQL> create tablespace albert datafile '+DG_DATA' size 1g;

Tablespace created.


SQL> select name from v$tablespace; 

NAME
------------------------------
SYSTEM
SYSAUX
UNDOTBS1
TEMP
UNDOTBS2
USERS
TBS_TEST_1025_1
TBS_TEST_1025_2
ALBERT --刚刚创建的表空间

     FILE# NAME
---------- -----------------------------------------------------------------
         1 +DG_DATA/Travelskydba/datafile/system.259.1002299725
         2 +DG_DATA/Travelskydba/datafile/sysaux.260.1002299741
         3 +DG_DATA/Travelskydba/datafile/undotbs1.261.1002299753
         4 +DG_DATA/Travelskydba/datafile/undotbs2.263.1002299769
         5 +DG_DATA/Travelskydba/datafile/users.264.1002299781
         6 +DG_DATA/Travelskydba/datafile/tbs_test_1025_1.269.1022603323
         7 +DG_DATA/Travelskydba/datafile/tbs_test_1025_2.270.1022603429
         8 +DG_DATA/Travelskydba/datafile/albert.271.1035217783


--备库:
SQL> select name from v$tablespace;

NAME
------------------------------
SYSTEM
SYSAUX
UNDOTBS1
TEMP
UNDOTBS2
USERS
TBS_TEST_1025_1
TBS_TEST_1025_2
ALBERT


SQL> select file#,name from v$datafile;

     FILE# NAME
---------- -----------------------------------------------------------------
         1 /oracle/oradata_Travelskydba/Travelskydba/system.259.1002299725
         2 /oracle/oradata_Travelskydba/Travelskydba/sysaux.260.1002299741
         3 /oracle/oradata_Travelskydba/Travelskydba/undotbs1.261.1002299753
         4 /oracle/oradata_Travelskydba/Travelskydba/undotbs2.263.1002299769
         5 /oracle/oradata_Travelskydba/Travelskydba/users.264.1002299781
         6 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_1.269.1022603323
         7 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_2.270.1022603429
         8 /oracle/oradata_Travelskydba/Travelskydba/albert.271.1035217783

8 rows selected.

一、加入including contents and datafiles

--主库删除:
SQL> drop tablespace albert including contents and datafiles;

Tablespace dropped.



--备库确认,正常删除掉
SQL> select file#,name from v$datafile;

     FILE# NAME
---------- -----------------------------------------------------------------
         1 /oracle/oradata_Travelskydba/Travelskydba/system.259.1002299725
         2 /oracle/oradata_Travelskydba/Travelskydba/sysaux.260.1002299741
         3 /oracle/oradata_Travelskydba/Travelskydba/undotbs1.261.1002299753
         4 /oracle/oradata_Travelskydba/Travelskydba/undotbs2.263.1002299769
         5 /oracle/oradata_Travelskydba/Travelskydba/users.264.1002299781
         6 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_1.269.1022603323
         7 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_2.270.1022603429

7 rows selected.

SQL> select name from v$tablespace;

NAME
------------------------------
SYSTEM
SYSAUX
UNDOTBS1
TEMP
UNDOTBS2
USERS
TBS_TEST_1025_1
TBS_TEST_1025_2

8 rows selected.


total 68780320
drwxr-xr-x 2 ora11g dba        4096 Oct 14 11:51 dataguardconfig
-rw-r----- 1 ora11g dba    24526848 Oct 23 15:31 stdctl02.ctl.bak
-rw-r----- 1 ora11g dba    24526848 Oct 23 15:31 stdctl01.ctl.bak
-rw-r----- 1 ora11g dba 10485768192 Oct 23 15:34 temp.262.1002299765
-rw-r----- 1 ora11g dba  2097160192 Mar 16 15:56 users.264.1002299781
-rw-r----- 1 ora11g dba 21474844672 Mar 16 15:56 tbs_test_1025_2.270.1022603429
-rw-r----- 1 ora11g dba 21474844672 Mar 16 15:56 tbs_test_1025_1.269.1022603323
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:35 sysaux.260.1002299741
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:35 undotbs1.261.1002299753
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:35 undotbs2.263.1002299769
-rw-r----- 1 ora11g dba  7340040192 Mar 16 16:35 system.259.1002299725
-rw-r----- 1 ora11g dba    24526848 Mar 16 16:35 stdctl02.ctl
-rw-r----- 1 ora11g dba    24526848 Mar 16 16:35 stdctl01.ctl

此时文件已经正常删除掉。


二、主库不加including contents and datafiles;

--主库创建文件:
SQL> create tablespace albert_leung datafile '+DG_DATA' size 2g;

Tablespace created.

--备库确认:

     FILE# NAME
---------- -----------------------------------------------------------------
         1 /oracle/oradata_Travelskydba/Travelskydba/system.259.1002299725
         2 /oracle/oradata_Travelskydba/Travelskydba/sysaux.260.1002299741
         3 /oracle/oradata_Travelskydba/Travelskydba/undotbs1.261.1002299753
         4 /oracle/oradata_Travelskydba/Travelskydba/undotbs2.263.1002299769
         5 /oracle/oradata_Travelskydba/Travelskydba/users.264.1002299781
         6 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_1.269.1022603323
         7 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_2.270.1022603429
         8 /oracle/oradata_Travelskydba/Travelskydba/albert_leung.271.1035218283

8 rows selected.

SQL> select name from v$tablespace; 

NAME
------------------------------
SYSTEM
SYSAUX
UNDOTBS1
TEMP
UNDOTBS2
USERS
TBS_TEST_1025_1
TBS_TEST_1025_2
ALBERT_LEUNG


drwxr-xr-x 2 ora11g dba        4096 Oct 14 11:51 dataguardconfig
-rw-r----- 1 ora11g dba    24526848 Oct 23 15:31 stdctl02.ctl.bak
-rw-r----- 1 ora11g dba    24526848 Oct 23 15:31 stdctl01.ctl.bak
-rw-r----- 1 ora11g dba 10485768192 Oct 23 15:34 temp.262.1002299765
-rw-r----- 1 ora11g dba  2097160192 Mar 16 15:56 users.264.1002299781
-rw-r----- 1 ora11g dba 21474844672 Mar 16 15:56 tbs_test_1025_2.270.1022603429
-rw-r----- 1 ora11g dba 21474844672 Mar 16 15:56 tbs_test_1025_1.269.1022603323
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:35 sysaux.260.1002299741
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:38 undotbs1.261.1002299753
-rw-r----- 1 ora11g dba  2147491840 Mar 16 16:38 albert_leung.271.1035218283
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:38 undotbs2.263.1002299769
-rw-r----- 1 ora11g dba  7340040192 Mar 16 16:38 system.259.1002299725
-rw-r----- 1 ora11g dba    24526848 Mar 16 16:38 stdctl02.ctl
-rw-r----- 1 ora11g dba    24526848 Mar 16 16:38 stdctl01.ctl


--主库删除文件:
SQL> drop tablespace albert_leung;

Tablespace dropped.

--备库数据字典:

SQL> select name from v$tablespace; 

NAME
------------------------------
SYSTEM
SYSAUX
UNDOTBS1
TEMP
UNDOTBS2
USERS
TBS_TEST_1025_1
TBS_TEST_1025_2

8 rows selected

SQL> select FILE#,NAME from v$datafile;

     FILE# NAME
---------- -----------------------------------------------------------------
         2 /oracle/oradata_Travelskydba/Travelskydba/sysaux.260.1002299741
         3 /oracle/oradata_Travelskydba/Travelskydba/undotbs1.261.1002299753
         4 /oracle/oradata_Travelskydba/Travelskydba/undotbs2.263.1002299769
         5 /oracle/oradata_Travelskydba/Travelskydba/users.264.1002299781
         6 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_1.269.1022603323
         7 /oracle/oradata_Travelskydba/Travelskydba/tbs_test_1025_2.270.1022603429

--可以看到,备库中的数据字典中已经删除掉,也就是说controlfile中该记录已经被删除

--但是观察到,备库文件系统,物理的数据文件还在,并没有删除。
[ora11g@vm-vmw45661-ora Travelskydba]$ ls -l
total 68780320
-rw-r----- 1 ora11g dba  2147491840 Mar 16 16:38 albert_leung.271.1035218283   --主库CHECKPOINT后不更新
drwxr-xr-x 2 ora11g dba        4096 Oct 14 11:51 dataguardconfig
-rw-r----- 1 ora11g dba    24526848 Mar 16 16:43 stdctl01.ctl
-rw-r----- 1 ora11g dba    24526848 Oct 23 15:31 stdctl01.ctl.bak
-rw-r----- 1 ora11g dba    24526848 Mar 16 16:43 stdctl02.ctl
-rw-r----- 1 ora11g dba    24526848 Oct 23 15:31 stdctl02.ctl.bak
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:41 sysaux.260.1002299741
-rw-r----- 1 ora11g dba  7340040192 Mar 16 16:41 system.259.1002299725
-rw-r----- 1 ora11g dba 21474844672 Mar 16 15:56 tbs_test_1025_1.269.1022603323
-rw-r----- 1 ora11g dba 21474844672 Mar 16 15:56 tbs_test_1025_2.270.1022603429
-rw-r----- 1 ora11g dba 10485768192 Oct 23 15:34 temp.262.1002299765
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:41 undotbs1.261.1002299753
-rw-r----- 1 ora11g dba  5242888192 Mar 16 16:41 undotbs2.263.1002299769
-rw-r----- 1 ora11g dba  2097160192 Mar 16 15:56 users.264.1002299781
[ora11g@vm-vmw45661-ora Travelskydba]$ 

--此时,可以使用操作系统命令rm删除掉文件系统中命名错误的数据文件,因为controlfile中已经没有此记录,所以不会涉及数据库的实例恢复。

这个实验,没有加上including contents and datafiles 我只是回答了他第一个问题,但是第二个问题:“为什么之前我删除tablespace的时候,也没有加,怎么就没事呢?

根因在于Oracle Managed Files,这次出问题的此套备库没有使用OMF特性,也就是drop tablespace后,Oracle不会帮你自动的去清理物理文件,只会删除controlfile中的记录,但是之前同事所提到的没事的状况,是因为备库为RAC+ASM架构,默认采用了OMF管理数据文件,所以及时没有添加 including contents and datafiles 也会帮你自动清理文件。

官方原文如下:

1、 Unlike files that are not managed by the database, when an Oracle managed data file or temp file is dropped, the filename is removed from the control file and the file is automatically deleted from the file 

2、 When recovery of a standby database encounters redo for the deletion of a tablespace, it deletes any Oracle managed data files in the local file system. Note that this is independent of the INCLUDING DATAFILES option issued at the primary database.

User_Profile设置成Default= Resuorce UNLIMITED?

前几日,有位新员工准备调整数据库中User_Profile的SESSIONS_PER_USER限制前抛出了一个结论:“如果把用户的Profile设置成Default后就等同于资源无限制了,百度搜索显示很多文章表明Default便代表无限制

很显然这个结论是不严谨或者是错误的,Oracle官方文档中已经有明确的说明:

“Specify DEFAULT if you want to omit a limit for this resource in this profile. A user assigned this profile is subject to the limit for this resource specified in the DEFAULT profile. The DEFAULT profile initially defines unlimited resources. You can change those limits with the ALTER PROFILE statement.

Any user who is not explicitly assigned a profile is subject to the limits defined in the DEFAULT profile. Also, if the profile that is explicitly assigned to a user omits limits for some resources or specifies DEFAULT for some limits, then the user is subject to the limits on those resources defined by the DEFAULT profile.”

也就是说,如果用户省略设置单独PROFILE, 分配此PROFILE的用户受Default Profile文件中指定的此资源的限制,如果之前没有修改DEFAULT PROFILE前,DEFAULT PROFILE中的资源限定是: unlimited ,也就是说,即使用户使用继承了Default Profile内容,众多数据库中配置不一,因为Default Profile是可以被修改的, 在没有确认Default Profile资源限制前不能下此结论即”Default Profile = unlimited resources”

为了帮助他今后思考更加严谨,做了一个实验给他:

SQL> select *from dba_profiles where profile='DEFAULT';

PROFILE                        RESOURCE_NAME                    RESOURCE LIMIT
------------------------------ -------------------------------- -------- ----------------------------------------
DEFAULT                        COMPOSITE_LIMIT                  KERNEL   UNLIMITED
DEFAULT                        SESSIONS_PER_USER                KERNEL   3
DEFAULT                        CPU_PER_SESSION                  KERNEL   UNLIMITED
DEFAULT                        CPU_PER_CALL                     KERNEL   UNLIMITED
DEFAULT                        LOGICAL_READS_PER_SESSION        KERNEL   UNLIMITED
DEFAULT                        LOGICAL_READS_PER_CALL           KERNEL   UNLIMITED
DEFAULT                        IDLE_TIME                        KERNEL   UNLIMITED
DEFAULT                        CONNECT_TIME                     KERNEL   UNLIMITED
DEFAULT                        PRIVATE_SGA                      KERNEL   UNLIMITED
DEFAULT                        FAILED_LOGIN_ATTEMPTS            PASSWORD 10
DEFAULT                        PASSWORD_LIFE_TIME               PASSWORD 180
DEFAULT                        PASSWORD_REUSE_TIME              PASSWORD UNLIMITED
DEFAULT                        PASSWORD_REUSE_MAX               PASSWORD UNLIMITED
DEFAULT                        PASSWORD_VERIFY_FUNCTION         PASSWORD VERIFY_FUNCTION_11G
DEFAULT                        PASSWORD_LOCK_TIME               PASSWORD 1
DEFAULT                        PASSWORD_GRACE_TIME              PASSWORD 7

16 rows selected.

SQL> create user liangce identified by liangce123;

User created.

SQL> grant connect,resource to liangce;

Grant succeeded.

SQL> select username,profile from dba_users where username='LIANGCE';

USERNAME                       PROFILE
------------------------------ ------------------------------
LIANGCE                        DEFAULT

开启3个会话,均执行:
SQL> conn liangce/liangce123;
Connected.

第4个会话:
SQL> conn liangce/liangce123;
ERROR:
ORA-02391: exceeded simultaneous SESSIONS_PER_USER limit
Warning: You are no longer connected to ORACLE.
创建新的PROFILE,并没有显示指定SESSIONS_PER_USER limit
SQL> CREATE PROFILE "LIANGCE"
  2      LIMIT
  3           COMPOSITE_LIMIT DEFAULT
         CPU_PER_SESSION DEFAULT
         CPU_PER_CALL DEFAULT
  4    5    6           LOGICAL_READS_PER_SESSION DEFAULT
  7           LOGICAL_READS_PER_CALL DEFAULT
  8           IDLE_TIME DEFAULT
  9           CONNECT_TIME DEFAULT
 10           PRIVATE_SGA DEFAULT
 11           FAILED_LOGIN_ATTEMPTS DEFAULT
 12           PASSWORD_LIFE_TIME DEFAULT
 13           PASSWORD_REUSE_TIME DEFAULT
 14           PASSWORD_REUSE_MAX DEFAULT
 15           PASSWORD_VERIFY_FUNCTION DEFAULT
 16           PASSWORD_LOCK_TIME DEFAULT
 17           PASSWORD_GRACE_TIME DEFAULT;

Profile created.

SQL> alter profile LIANGCE limit SESSIONS_PER_USER 2;

Profile altered.

SQL> select *from dba_profiles where PROFILE='LIANGCE';

PROFILE                        RESOURCE_NAME                    RESOURCE LIMIT
------------------------------ -------------------------------- -------- ----------------------------------------
LIANGCE                        COMPOSITE_LIMIT                  KERNEL   DEFAULT
LIANGCE                        SESSIONS_PER_USER                KERNEL   2
LIANGCE                        CPU_PER_SESSION                  KERNEL   DEFAULT
LIANGCE                        CPU_PER_CALL                     KERNEL   DEFAULT
LIANGCE                        LOGICAL_READS_PER_SESSION        KERNEL   DEFAULT
LIANGCE                        LOGICAL_READS_PER_CALL           KERNEL   DEFAULT
LIANGCE                        IDLE_TIME                        KERNEL   DEFAULT
LIANGCE                        CONNECT_TIME                     KERNEL   DEFAULT
LIANGCE                        PRIVATE_SGA                      KERNEL   DEFAULT
LIANGCE                        FAILED_LOGIN_ATTEMPTS            PASSWORD DEFAULT
LIANGCE                        PASSWORD_LIFE_TIME               PASSWORD DEFAULT
LIANGCE                        PASSWORD_REUSE_TIME              PASSWORD DEFAULT
LIANGCE                        PASSWORD_REUSE_MAX               PASSWORD DEFAULT
LIANGCE                        PASSWORD_VERIFY_FUNCTION         PASSWORD DEFAULT
LIANGCE                        PASSWORD_LOCK_TIME               PASSWORD DEFAULT
LIANGCE                        PASSWORD_GRACE_TIME              PASSWORD DEFAULT

SQL> alter user liangce PROFILE LIANGCE;

User altered.

SQL> select username,profile from dba_users where username='LIANGCE';

USERNAME                       PROFILE
------------------------------ ------------------------------
LIANGCE                        LIANGCE

此时,才不会继续继承DEFAULT的配置,SESSIONS_PER_USER 为2,只能再一个实例中登录2个会话,RAC多个实例中单独计算,不进行累计。

DataGuard 切换流程梳理(三)- 命令行 Switchover

虽然我们生产目前DataGuard的切换主要依赖于 DataGuard Broker工具,但是日常工作中经常会发现Broker出现配置问题导致无法正常切换,准备好DG切换的标准SQL*PLUS的命令行方式才是万全之策。

1.切换前确认主备库是否具备切换条件,关注是否Error与delay_time
select thread#,
       DB_UNIQUE_NAME,
       DEST_NAME,
       TARGET,
       DATABASE_MODE,
       error,
       RECOVERY_MODE,
       GAP_STATUS,
       APPLIED_SEQ#,
       current_scn,
       applied_scn,
       to_char((scn_to_timestamp(current_scn)),'yyyymmdd hh24:mi:ss') current_scn_time,
       to_char((scn_to_timestamp(applied_scn)),'yyyymmdd hh24:mi:ss') applied_scn_time,
       scn_to_timestamp(current_scn)- scn_to_timestamp(current_scn) as delay_time
  from (SELECT al.thread#,
               ads.dest_id,
               ads.DEST_NAME,
               ads.TYPE || ' ' || ad.TARGET TARGET,
               ADS.DATABASE_MODE,
               ads.STATUS,
               ads.error,
               ads.RECOVERY_MODE,
               ads.DB_UNIQUE_NAME,
               ads.DESTINATION,
               ads.GAP_STATUS,
               (SELECT sequence#
                  FROM v$log na
                 WHERE na.thread# = al.thread#
                   and status = 'CURRENT') Current_Seq#,
               Last_Archived,
               al.APPLIED_SEQ#,
               ad.applied_scn,
               current_scn
          FROM (SELECT dest_id,
                       thread#,
                       d.current_scn,
                       MAX(sequence#) Last_Archived,
                       max(CASE
                             WHEN APPLIED = 'YES' THEN
                              sequence#
                           end) APPLIED_SEQ#
                  FROM v$archived_log V, v$database d
                 WHERE V.resetlogs_change# = d.RESETLOGS_CHANGE#
                 group by dest_id, thread#, d.current_scn) al,
               v$archive_dest_status ads,
               v$archive_dest AD
         WHERE al.dest_id(+) = ads.dest_id 
           AND ads.STATUS != 'INACTIVE'
           AND AD.DEST_ID = ADS.DEST_ID and ad.APPLIED_SCN <> 0
         ORDER BY al.thread#, ads.dest_id);

SQL> select name,database_role,switchover_status from v$database;
       --确认为 to stanby或SESSIONS ACTIVE状态
2.SERVICE处理:
备库添加:
SQL> show parameter service;

NAME                  TYPE        VALUE
------------------- ----------- ------------------------------
service_names       string      ORA1436B,dbaas

SQL> alter system set service_names='ORA1436B,dbaas,Albert';

System altered.

SQL> show parameter service;

NAME                  TYPE        VALUE
----------------    ----------- ------------------------------
service_names         string      ORA1436B,dbaas,Albert


主库修改:
SQL> show parameter service; 

NAME                  TYPE        VALUE
--------------     ----------- ------------------------------
service_names         string      ORA1436B,dbaas,Albert

SQL> alter system set service_names='ORA1436B,dbaas';

System altered.

SQL> show parameter service;

NAME                   TYPE        VALUE
-------------        ----------- ------------------------------
service_names        string      ORA1436B,dbaas
3.RAC主库切换前保留1个节点
登陆到主库其他节点
SQL>SHUTDOWN IMMEDIATE
4.主库SWITCHOVER
SQL> ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY; 
或 
SQL> ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY with session shutdown; 

注:如果有主库有活动的 session 可以使用此选项,否则转换会遇到 ORA-01093 错误或直接KILL活动会话
5.主库打开至Mount状态:
sqlplus / as sysdba 
SQL> startup mount 
6.备库SWITCH OVER操作
检查备库状态,是否可以切换
SQL> select name,database_role,switchover_status from v$database; 
--确认是否为to primary

原备库取消恢复进程:
SQL> alter database recover managed standby database cancel;

原备库(新主库)switchover 操作
SQL> ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY; 

可能会抛出报ORA-16139: media recovery required,是是由于未应用日志引起,西药先执行执行 :
SQL> ALTER DATABASE RECOVER MANAGED STANDBY DATABASE DISCONNECT 
FROM SESSION;
7.原备库(新主库)重启
SQL> shutdown immediate 
SQL> startup
如不重启,新备库MRP进程则会一直处于WAIT_FOR_LOG的状态
8.原主库,新备库启用日志应用: 
SQL> ALTER DATABASE RECOVER MANAGED STANDBY DATABASE USING CURRENT LOGFILE DISCONNECT; 
9.确认主备库数据库数据字典状态与数据库日志有无异常,报错
select name,db_unique_name,database_role,open_mode from v$database;

主库进行日志切换,查看备库的日志,看是否开始接收并应用
SQL>select process,status,client_process,thread#,sequence#,block#,active_agents,known_agents from gv$managed_standby where process in ('LNS','RFS','MRP0') and THREAD# <> 0

数据库性能问题导致应用单次SQL效率10ms变为10s

昨日,同事发来一则微信反馈前一天晚应用SQL查询缓慢,原本10ms内能完成的查询SQL在一时间段内:19号22:10到22:45突然执行效率下降到10分钟,然而在22:45后自动恢复正常,想分析一下根因。数据库为一套2节点RAC,Linux -x86 数据库版本为11.2.0.4。

有了明确的时间段,登录到数据库内看看到底这个期间产生了什么性能问题?

数据库DB_TIME、活动会话数与应用反馈的时间基本吻合,从22点10分开始,数据库中的Active_Session数量开始飙升,并且数据库活动会话基本都被Library Cache Lock与Cursor Pin S wait on X等待事件所阻塞。

故障时间段内Top Event百分比

从ASH中看,活动会话最早被节点1的4327会话所阻塞,并且等待的是LIBRARY CACHE LOCK,随后,开始出现sql尝试软解析,遭遇Cursor pin s wait on x,且被节点1的2060会话所阻塞

我们看一下4237与2060在故障期间在干什么?

4327这个会话为oracle auto_task的sql auto tunning advisor job,并且他持有了Library Cache Lock Handle “0x1f9bc9bb98″导致了会话3877想以Mode=3(X)独占模式持有Library Cache Lock不成功,被阻塞。
2060为正常的应用会话,并且同样等待LIBRARY CACHE LOCK,没有阻塞者,这是一个奇怪的现象

但是2060会话在systemstate dump的trace文件中找到阻塞者,同样被4327会话阻塞

从相同时间段的systemstate dump trace文件中看到,2060会话在等待library cache lock,申请的同样是0x1f9bc9bb98的Library Cache Lock Handle (Mode=2(s) 共享模式),虽然没有Dump出2060的阻塞者,但是从申请的Handle上可以推断,都是被4327会话sql auto tunning advisor job阻塞。

分析结论: 此时间段确实为oracle autotask作业的时间窗口,但是job会话并不会长时间持有Library Cache Lock,这个会话当时在等待db file scattered read,数据库当时物理读非常高并且io链路上没有明显异常,异常点1:此JOB作业长时间持有LIBRARY CACHE LOCK不释放且JOB涉及的SQL造成物理读很高,异常点2:内存lock与Mutex争用又会导致cpu Idle低,从而进一步导致io无法调度完成,造成会话JOB工作效率下降,从而没有及时的释放LIBRARY CACHE LOCK的可能性会加大,这些都是非常不正常的行为,所以我决定disable sql tunning advisor功能,规避此问题再次发生。

DataGuard 切换流程梳理(二)-Broker fiailover

DG Failover一般作为数据库主库故障的应急处理,不保证备库数据完整性,请谨慎选择。

Failover之后不存在主库、备库关系。如主库可启动到Mount阶段,可在主库执行alter system flush redo to ‘备库’;确保主库online redo log内容同步到备库节点,最大限度上保证Failover前后数据不丢失。

主库已发生故障,且不可恢复,启动failover应急手段处理:
[ora11g@]$ dgmgrl
DGMGRL for Linux: Version 11.2.0.4.0 - 64bit Production

Copyright (c) 2000, 2009, Oracle. All rights reserved.

Welcome to DGMGRL, type "help" for information.
DGMGRL> connect sys
Password:
Connected.
DGMGRL> show configuration

Configuration - DG_Config

  Protection Mode: MaxPerformance
  Databases:
    ora1436b    - Primary database
    ora1436bstd - Physical standby database

Fast-Start Failover: DISABLED

Configuration Status:
ORA-01034: ORACLE not available
ORA-16625: cannot reach database "ora1436b"
DGM-17017: unable to determine configuration status

DGMGRL> show database ora1436bstd

Database - ora1436bstd

  Role:            PHYSICAL STANDBY
  Intended State:  APPLY-ON
  Transport Lag:   0 seconds (computed 105 seconds ago)
  Apply Lag:       0 seconds (computed 105 seconds ago)
  Apply Rate:      49.00 KByte/s
  Real Time Query: OFF
  Instance(s):
    ORA1436B

  Database Warning(s):
    ORA-16857: standby disconnected from redo source for longer than specified threshold

Database Status:
WARNING

--执行failover操作:
DGMGRL> failover to ora1436bstd
Performing failover NOW, please wait...
Failover succeeded, new primary is "ora1436bstd"

确认备库v$database视图 database_role是否为“primary ”并且观察alert日志是否出现异常报错信息。

ORA-00600: internal error code, arguments: [kcbzwfcro_2] 故障案例一则

上周末,一套RAC生产库实例1 alert日志中出现大量ORA-00600报错,触发了监控报警,当时值班人员重启数据库实例后恢复。实例重启应急操作过程中正常一致性关闭未果,而是kill lgwr进程得以让实例终止。

Sat Feb 08 02:34:03 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc  (incident=193747):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Incident details in: /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/incident/incdir_193747/Travelskydba1_p000_166150_i193747.trc
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 02:34:05 2020
 Dumping diagnostic data in directory=[cdmp_20200208023405], requested by (instance=1, osid=166150 (P000)), summary=[incident=193747].
 Sat Feb 08 02:34:05 2020
 Sweep [inc][193747]: completed
 Sweep [inc2][193747]: completed
 Sat Feb 08 02:36:14 2020
 ALTER SYSTEM ARCHIVE LOG
 Sat Feb 08 02:36:14 2020
 Thread 1 advanced to log sequence 29734 (LGWR switch)
   Current log# 2 seq# 29734 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_2.258.975692641
   Current log# 2 seq# 29734 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_2.259.975692641
 Sat Feb 08 02:36:14 2020
 LNS: Standby redo logfile selected for thread 1 sequence 29734 for destination LOG_ARCHIVE_DEST_2
 Archived Log entry 179716 added for thread 1 sequence 29733 ID 0xd45ba67e dest 1:
 ALTER SYSTEM ARCHIVE LOG
 Sat Feb 08 02:36:25 2020
 Thread 1 advanced to log sequence 29735 (LGWR switch)
   Current log# 3 seq# 29735 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_3.260.975692643
   Current log# 3 seq# 29735 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_3.261.975692645
 Sat Feb 08 02:36:25 2020
 Archived Log entry 179724 added for thread 1 sequence 29734 ID 0xd45ba67e dest 1:
 Sat Feb 08 02:36:25 2020
 LNS: Standby redo logfile selected for thread 1 sequence 29735 for destination LOG_ARCHIVE_DEST_2
 Sat Feb 08 02:39:25 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p046_192910.trc  (incident=195547):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Incident details in: /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/incident/incdir_195547/Travelskydba1_p046_192910_i195547.trc
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Sat Feb 08 02:39:26 2020
 Dumping diagnostic data in directory=[cdmp_20200208023926], requested by (instance=1, osid=192910 (P046)), summary=[incident=195547].
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p046_192910.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p046_192910.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 02:39:26 2020
 SMON: Restarting fast_start parallel rollback
 Sat Feb 08 02:39:27 2020
 Sweep [inc][195547]: completed
 Sweep [inc2][195547]: completed
 Sat Feb 08 02:44:39 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p002_190908.trc  (incident=193795):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Incident details in: /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/incident/incdir_193795/Travelskydba1_p002_190908_i193795.trc
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p002_190908.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p002_190908.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 02:44:41 2020
 Dumping diagnostic data in directory=[cdmp_20200208024441], requested by (instance=1, osid=190908 (P002)), summary=[incident=193795].
 Sat Feb 08 02:44:43 2020
 Sweep [inc][193795]: completed
 Sweep [inc2][193795]: completed
 Sat Feb 08 02:50:02 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_53435.trc  (incident=193859):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Incident details in: /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/incident/incdir_193859/Travelskydba1_p005_53435_i193859.trc
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_53435.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_53435.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 02:50:03 2020
 SMON: Restarting fast_start parallel rollback
 Sat Feb 08 02:50:03 2020
 Dumping diagnostic data in directory=[cdmp_20200208025003], requested by (instance=1, osid=53435 (P005)), summary=[incident=193859].
 Sat Feb 08 02:50:04 2020
 Sweep [inc][193859]: completed
 Sweep [inc2][193859]: completed
 Sat Feb 08 02:55:15 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc  (incident=193748):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Incident details in: /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/incident/incdir_193748/Travelskydba1_p000_166150_i193748.trc
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Sat Feb 08 02:55:16 2020
 Dumping diagnostic data in directory=[cdmp_20200208025516], requested by (instance=1, osid=166150 (P000)), summary=[incident=193748].
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 02:55:19 2020
 Sweep [inc][193748]: completed
 Sweep [inc2][193748]: completed
 Sat Feb 08 03:00:37 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_104212.trc  (incident=193796):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_104212.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_104212.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:00:37 2020
 SMON: Restarting fast_start parallel rollback
 Sat Feb 08 03:05:49 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc  (incident=193749):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:11:10 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_155132.trc  (incident=193787):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_155132.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_155132.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:11:10 2020
 SMON: Restarting fast_start parallel rollback
 Sat Feb 08 03:13:29 2020
 Stopping background process CJQ0
 Sat Feb 08 03:16:22 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc  (incident=193750):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:21:43 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_17817.trc  (incident=193531):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_17817.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_17817.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:21:43 2020
 SMON: Restarting fast_start parallel rollback
 Sat Feb 08 03:26:55 2020
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:32:15 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_65986.trc  (incident=193491):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_65986.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_65986.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:32:15 2020
 SMON: Restarting fast_start parallel rollback
 Sat Feb 08 03:36:11 2020
 ALTER SYSTEM ARCHIVE LOG
 Sat Feb 08 03:36:12 2020
 Thread 1 advanced to log sequence 29736 (LGWR switch)
   Current log# 4 seq# 29736 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_4.262.975692647
   Current log# 4 seq# 29736 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_4.263.975692649
 Sat Feb 08 03:36:12 2020
 LNS: Standby redo logfile selected for thread 1 sequence 29736 for destination LOG_ARCHIVE_DEST_2
 Sat Feb 08 03:36:13 2020
 Archived Log entry 179730 added for thread 1 sequence 29735 ID 0xd45ba67e dest 1:
 Sat Feb 08 03:36:24 2020
 ALTER SYSTEM ARCHIVE LOG
 Sat Feb 08 03:36:27 2020
 Thread 1 advanced to log sequence 29737 (LGWR switch)
   Current log# 5 seq# 29737 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_5.264.975692651
   Current log# 5 seq# 29737 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_5.265.975692651
 Sat Feb 08 03:36:27 2020
 LNS: Standby redo logfile selected for thread 1 sequence 29737 for destination LOG_ARCHIVE_DEST_2
 Archived Log entry 179738 added for thread 1 sequence 29736 ID 0xd45ba67e dest 1:
 Sat Feb 08 03:37:28 2020
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p000_166150.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:39:16 2020
 Shutting down instance (immediate)
 Stopping background process SMCO
 Shutting down instance: further logons disabled
 Stopping background process QMNC
 Stopping background process MMNL
 Stopping background process MMON
 License high water mark = 375
 Sat Feb 08 03:42:48 2020
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_114400.trc  (incident=193539):
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Incident details in: /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/incident/incdir_193539/Travelskydba1_p005_114400_i193539.trc
 Use ADRCI or Support Workbench to package the incident.
 See Note 411.1 at My Oracle Support for error and packaging details.
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_114400.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Errors in file /opt/app/ora11g/diag/rdbms/Travelskydba/Travelskydba1/trace/Travelskydba1_p005_114400.trc:
 ORA-10388: parallel query server interrupt (failure)
 ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
 Sat Feb 08 03:42:49 2020
 SMON: Restarting fast_start parallel rollback


从alert日志中我们发现,基本上ORA-00600与ORA-10388成对出现,并且SMON在回滚并行进程,ORA-00600的trace文件也是并行进程-Travelskydba1_p00产生。

查看报错trace文件:

*** 2020-02-08 02:55:15.334
*** SESSION ID:(3707.19965) 2020-02-08 02:55:15.334
*** SERVICE NAME:(SYS$BACKGROUND) 2020-02-08 02:55:15.334
 
Incident 193748 created, dump file: /opt/app/ora11g/diag/rdbms/ora624a/ora624a1/incident/incdir_193748/ora624a1_p000_166150_i193748.trc
ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []

fatal error occurred while scanning redo
ORA-10388: parallel query server interrupt (failure)
ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
Error 10388 occurred while dumping log
ORA-10388: parallel query server interrupt (failure)
ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
Parallel Transaction recovery coordinatorcaught exception 10388

*** 2020-02-08 02:55:25.706
*** SESSION ID:(3707.19967) 2020-02-08 02:55:25.707
*** SERVICE NAME:(SYS$BACKGROUND) 2020-02-08 02:55:25.707
 
Parallel Transaction recovery coordinatorcaught exception 10388
DDE: Problem Key 'ORA 600 [kcbzwfcro_2]' was flood controlled (0x2) (incident: 193749)

*** 2020-02-08 03:05:49.294
*** SESSION ID:(3709.435) 2020-02-08 03:05:49.294
*** SERVICE NAME:(SYS$BACKGROUND) 2020-02-08 03:05:49.294
 
ORA-00600: internal error code, arguments: [kcbzwfcro_2], [136046], [1], [32768], [0], [], [], [], [], [], [], []
Potentially stale force-CR-override buffer found before OBJD MISMATCH check.
This issue should be investigated by both cache fusion and space layer.
BH (0x132f60d8d8) file#: 15 rdba: 0x03c01ae3 (15/6883) class: 1 ba: 0x132e6be000
  set: 75 pool: 3 bsz: 8192 bsi: 0 sflg: 1 pwc: 0,3
  dbwrid: 2 obj: 136046 objn: 136046 tsn: 10 afn: 15 hint: f
  hash: [0x164ee2ecd0,0xe6f484db0] lru: [0xf1f515308,0xf1f51b968]
  ckptq: [NULL] fileq: [NULL] objq: [0x106f19fe10,0x12cec34f10] objaq: [0xf2f496400,0xf2f473b80]
  st: XCURRENT md: NULL fpin: 'kdgwh05: kdglfe' tch: 0 le: 0x3afe991a8
  flags: block_written_once redo_since_read remote_transfered
          force_cr_override
  LRBA: [0x0.0.0] LSCN: [0x0.0] HSCN: [0xffff.ffffffff] HSUB: [1]
GLOBAL CACHE ELEMENT DUMP (address: 0x3afe991a8):
  id1: 0x1ae3 id2: 0xf pkey: OBJ#136046 block: (15/6883)
  lock: X rls: 0x0 acq: 0x0 latch: 23
  flags: 0x20 fair: 0 recovery: 0 fpin: 'kdgwh05: kdglfe'
  bscn: 0x0.1c9bcdb5 bctx: (nil) write: 0 scan: 0x0 
  lcp: (nil) lnk: [NULL] lch: [0x132f60da10,0x132f60da10]
  seq: 72 hist: 113 238 180 113 238 180 113 238 180 113 238 180 113 238 180 113
    238 180 113 238
  LIST OF BUFFERS LINKED TO THIS GLOBAL CACHE ELEMENT:
    flg: 0x0a200000 sflg: 0x2000 state: XCURRENT tsn: 10 tsh: 0
      addr: 0x132f60d8d8 obj: 136046 cls: DATA bscn: 0x0.1c9bcdb5
  buffer tsn: 10 rdba: 0x03c01ae3 (15/6883)
  scn: 0x0000.1c9bcdb5 seq: 0x01 flg: 0x04 tail: 0xcdb50601
  frmt: 0x02 chkval: 0x84e4 type: 0x06=trans data
堆栈信息:
----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
skdstdst()+41        call     kgdsdst()            000000000 ? 000000000 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
ksedst1()+103        call     skdstdst()           000000000 ? 000000000 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
ksedst()+39          call     ksedst1()            000000000 ? 000000001 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbkedDefDump()+2746  call     ksedst()             000000000 ? 000000001 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
ksedmp()+41          call     dbkedDefDump()       000000003 ? 000000002 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
ksfdmp()+69          call     ksedmp()             000000003 ? 000000002 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbgexPhaseII()+1764  call     ksfdmp()             000000003 ? 000000002 ?
                                                   7FFDF8B56F90 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbgexExplicitEndInc  call     dbgexPhaseII()       7F96E5CAD730 ? 7F96E5CB4700 ?
()+755                                             7FFDF8B5FDA8 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbgeEndDDEInvocatio  call     dbgexExplicitEndInc  7F96E5CAD730 ? 7F96E5CB4700 ?
nImpl()+769                   ()                   7FFDF8B5FDA8 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbgeEndSpltInvokOnR  call     dbgeEndDDEInvocatio  7F96E5CAD730 ? 7F96E5CB4700 ?
ec()+270                      nImpl()              7FFDF8B5FDA8 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbgePostErrorKGE()+  call     dbgeEndSpltInvokOnR  7F96E5CAD730 ? 7F96E5CB4700 ?
257                           ec()                 7FFDF8B5FDA8 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
dbkePostKGE_kgsf()+  call     dbgePostErrorKGE()   00C113DA0 ? 7F96E5CBCCC0 ?
71                                                 000002894 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
kgeselv()+276        call     dbkePostKGE_kgsf()   00C113DA0 ? 7F96E5CBCCC0 ?
                                                   000002894 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000002 ?
ksesecl0()+162       call     kgeselv()            00C113DA0 ? 7F96E5CBCCC0 ?
                                                   000002894 ? 7FFDF8B57068 ?
                                                   7FFDF8B5BB10 ? 000000000 ?
ksucin()+147         call     ksesecl0()           00C113DA0 ? 7F96E5CBCCC0 ?
                                                   000002894 ? 000000000 ?
                                                   0000000B0 ? 000000000 ?
krr_thread_read()+8  call     ksucin()             00C113DA0 ? 7F96E5CBCCC0 ?
067                                                000002894 ? 000000000 ?
                                                   0000000B0 ? 000000000 ?
krr_read_buffer()+2  call     krr_thread_read()    7F96E42A0888 ? 000000002 ?
8                                                  000000000 ? 000000000 ?
                                                   7FFDF8B615A0 ? 7FFDF8B615A4 ?
krr_parse_redo()+12  call     krr_read_buffer()    7F96E42A0888 ? 000000002 ?
512                                                000000000 ? 000000000 ?
                                                   7FFDF8B615A0 ? 7FFDF8B615A4 ?
kcra_scan_redo()+11  call     krr_parse_redo()     7F96E42A0888 ? 000000002 ?
867                                                000000000 ? 000000000 ?
                                                   000000000 ? 7FFDF8B615A4 ?
kcra_dump_redo()+21  call     kcra_scan_redo()     7FFDF8B64560 ? 000000001 ?
04                                                 7FFDF8B640CC ? 000000000 ?
                                                   000000000 ? 7FFDF8B615A4 ?
kcra_dump_redo_inte  call     kcra_dump_redo()     7FFDF8B64560 ? 000000001 ?
rnal()+3362                                        7FFDF8B640CC ? 000000000 ?
                                                   000000000 ? 7FFDF8B615A4 ?
kcbzwfcro()+997      call     kcra_dump_redo_inte  7FFDF8B64C40 ? 7FFDF8B64C44 ?
                              rnal()               7FFDF8B64C48 ? 000000001 ?
                                                   1300000000 ? 1F00000000 ?
kcbgcur()+10141      call     kcbzwfcro()          132F60D8D8 ? 7FFDF8B685B0 ?
                                                   1F3953EC68 ? 000000001 ?
                                                   1300000000 ? 1F00000000 ?
ktbgcur()+123        call     kcbgcur()            7FFDF8B685B0 ? 000000002 ?
                                                   0000003C5 ? 000000000 ?
                                                   1300000000 ? 1F00000000 ?
kturGetCurPinForUnd  call     ktbgcur()            7FFDF8B685A0 ? 000000002 ?
o()+264                                            0000003C5 ? 000000000 ?
                                                   1300000000 ? 1F00000000 ?
kdiulk()+16575       call     kturGetCurPinForUnd  7FFDF8B685A0 ? 000000002 ?
                              o()                  0000003C5 ? 000000000 ?
                                                   0063CDCD8 ? 1F00000000 ?
kcoubk()+366         call     kdiulk()             7F96E5CC0E10 ? 18A5AF8518 ?
                                                   000000004 ? 000000080 ?
                                                   000000000 ? 1F00000000 ?
ktprundo_intra()+10  call     kcoubk()             7FFDF8B6874C ? 7F96E5CC0E10 ?
73                                                 18A5AF8518 ? 000000004 ?
                                                   000000080 ? 000000000 ?
ktprits()+1218       call     ktprundo_intra()     18A5620EA0 ? 18AD9DA7D0 ?
                                                   18A5AF8518 ? 000000004 ?
                                                   000000080 ? 000000000 ?
ktprmai()+213        call     ktprits()            7FFDF8B68A40 ? 18AD9DA7D0 ?
                                                   18A5AF8518 ? 000000004 ?
                                                   000000080 ? 000000000 ?
kxfprdp()+1466       call     ktprmai()            7FFDF8B68A40 ? 18AD9DA7D0 ?
                                                   18A5AF8518 ? 000000004 ?
                                                   000000080 ? 000000000 ?
opirip()+913         call     kxfprdp()            7FFDF8B68A40 ? 18AD9DA7D0 ?
                                                   1F4D61F8A0 ? 000000004 ?
                                                   000000080 ? 000000000 ?
opidrv()+603         call     opirip()             000000032 ? 000000004 ?
                                                   7FFDF8B69FE8 ? 000000004 ?
                                                   000000080 ? 000000000 ?
sou2o()+103          call     opidrv()             000000032 ? 000000004 ?
                                                   7FFDF8B69FE8 ? 000000004 ?
                                                   000000080 ? 000000000 ?
opimai_real()+250    call     sou2o()              7FFDF8B69FC0 ? 000000032 ?
                                                   000000004 ? 7FFDF8B69FE8 ?
                                                   000000080 ? 000000000 ?
ssthrdmain()+265     call     opimai_real()        000000000 ? 7FFDF8B6A1B0 ?
                                                   000000004 ? 7FFDF8B69FE8 ?
                                                   000000080 ? 000000000 ?
main()+201           call     ssthrdmain()         000000003 ? 7FFDF8B6A1B0 ?
                                                   000000001 ? 000000000 ?
                                                   000000080 ? 000000000 ?
__libc_start_main()  call     main()               000000003 ? 7FFDF8B6A350 ?
+253                                               000000001 ? 000000000 ?
                                                   000000080 ? 000000000 ?
_start()+41          call     __libc_start_main()  000A2A344 ? 000000001 ?
                                                   7FFDF8B6A348 ? 000000000 ?
                                                   000000080 ? 000000000 ?

根据trace文件,似乎与RAC间CR Block传输覆盖版本冲突有关:Potentially stale force-CR-override buffer found before OBJD MISMATCH check.

带着疑惑搜寻Mos(Oracle Support)后,确认此问题为Bug导致(ORA-600:[kcbzwfcro_2] Reported in Alert.log (Doc ID 2085507.1)

故障现象,Call Stack信息基本一致,并且Oracle给予了Workround

_gc_override_force_cr参数简单解释:if TRUE, try to override force-cr requests,在Undo header中会标识这个CR块是否为force_cr_override的flag,但是这个代表何意没有找到具体的官方解释,猜测是在节点间传输时本地CR与远程CR校验时出现错误,本地与远程均认为自己是最新版本CR。本次故障找到原因,但是此参数的含义还有继续找寻资料确认。

DataGuard 切换流程梳理(一)-Broker switchover

近期手头有 一项重要工作便是重新梳理Dataguard切换流程与注意事项,以便团队在数据库应急时更加熟练从容的进行容灾切换,主要分为四部分:

1.Broker Switcher

2.Broker Failover

3.命令行 switcher over

4.命令行Failover

5.命令行Failover怎样保证数据不丢失

一.操作前准备

操作前首先要确认主备库的ip、tnsnames、主备库的DB_UNIQUE_NAME、主备库目前DG配置状态,日志同步状态,主备库连接Process数,应用SERVICE处理、SERVICE在监听上注册情况等。检查点比较多,极有可能存在应急操作前没有足够的时间去确保各项检查点的正确性,所以这里罗列出来是为了提醒用途,DG切换成功与否需要以上检查内容的保证。

1.1 确认主备库的tnsnames与ip

主库
IP:181.208
机器名:liangce-ora
DB_UNQIUE_NAME:ORALIANGCE

备库
181.209
机器名:liangcestd-ora
DB_UNIQUE_NAME:ORALIANGCEstd

登录主备库确认$ORACLE_HOME/network/admin目录确认tnsnames.ora文件中的内容,确认ip对应的连接串是否如主库、备库配置如预期,并且tns别名中的配置信息进行DB_UNIQUE_NAME确认

1.2 确认主备库的process配置

为什么要确认此项配置?因为会存在主库多节点RAC+DG单机的情况,也就是说是否存在备库的单机process连接数足够承载RAC多节点的应用连接?

1.3 应用SERVICE处理

我们目前应用SERVICE只注册在主库上,并且应用目前使用的连接串是有DG配置的,如果在切换后主库不处理应用SERVICE,会导致ORA-O1033错误,详情请见早起文章:《中秋节快乐–中秋节前DataGuard切换演练产生问题》

备库:
SQL> show parameter service;

NAME                      TYPE        VALUE
---------------------- ----------- ------------------------------
service_names             string      ORALIANGCE,dbaas

SQL> alter system set service_names='ORALIANGCE,dbaas,Albert';

System altered.

SQL> show parameter service;

NAME                       TYPE        VALUE
----------------------- ----------- ------------------------------
service_names               string      ORALIANGCE,dbaas,Albert



主库:
SQL> show parameter service; 

NAME                        TYPE        VALUE
------------------------- ----------- ------------------------------
service_names               string      ORALIANGCE,dbaas,Albert

SQL> alter system set service_names='ORALIANGCE,dbaas';

System altered.

SQL> show parameter service;

NAME                          TYPE        VALUE
--------------------------- ----------- ------------------------------
service_names                  string      ORALIANGCE,dbaas

1.4 主备库配置,同步传输确认

主库上执行:

select thread#,
       DB_UNIQUE_NAME,
       DEST_NAME,
       TARGET,
       DATABASE_MODE,
       error,
       RECOVERY_MODE,
       GAP_STATUS,
       APPLIED_SEQ#,
       current_scn,
       applied_scn,
       to_char((scn_to_timestamp(current_scn)),'yyyymmdd hh24:mi:ss') current_scn_time,
       to_char((scn_to_timestamp(applied_scn)),'yyyymmdd hh24:mi:ss') applied_scn_time,
       scn_to_timestamp(current_scn)- scn_to_timestamp(current_scn) as delay_time
  from (SELECT al.thread#,
               ads.dest_id,
               ads.DEST_NAME,
               ads.TYPE || ' ' || ad.TARGET TARGET,
               ADS.DATABASE_MODE,
               ads.STATUS,
               ads.error,
               ads.RECOVERY_MODE,
               ads.DB_UNIQUE_NAME,
               ads.DESTINATION,
               ads.GAP_STATUS,
               (SELECT sequence#
                  FROM v$log na
                 WHERE na.thread# = al.thread#
                   and status = 'CURRENT') Current_Seq#,
               Last_Archived,
               al.APPLIED_SEQ#,
               ad.applied_scn,
               current_scn
          FROM (SELECT dest_id,
                       thread#,
                       d.current_scn,
                       MAX(sequence#) Last_Archived,
                       max(CASE
                             WHEN APPLIED = 'YES' THEN
                              sequence#
                           end) APPLIED_SEQ#
                  FROM v$archived_log V, v$database d
                 WHERE V.resetlogs_change# = d.RESETLOGS_CHANGE#
                 group by dest_id, thread#, d.current_scn) al,
               v$archive_dest_status ads,
               v$archive_dest AD
         WHERE al.dest_id(+) = ads.dest_id 
           AND ads.STATUS != 'INACTIVE'
           AND AD.DEST_ID = ADS.DEST_ID and ad.APPLIED_SCN <> 0
         ORDER BY al.thread#, ads.dest_id)
在主库上执行即可,可以确认主备库的一些基本配置与Current SCN,Applied SCN,Delay_time等

主库上执行:

[ora11g@~]$ dgmgrl
DGMGRL for Linux: Version 11.2.0.4.0 - 64bit Production

Copyright (c) 2000, 2009, Oracle. All rights reserved.

Welcome to DGMGRL, type "help" for information.
DGMGRL> connect sys
Password:
Connected.
DGMGRL> show configuration 

Configuration - DG_Config

  Protection Mode: MaxPerformance
  Databases:
    ORALIANGCE    - Primary database
    ORALIANGCEstd - Physical standby database

Fast-Start Failover: DISABLED

Configuration Status:
SUCCESS


2、查看主备库数据传输是否异常
DGMGRL> 
DGMGRL> show database ORALIANGCEstd  

Database - ORALIANGCEstd

  Role:            PHYSICAL STANDBY
  Intended State:  APPLY-ON
  Transport Lag:   0 seconds (computed 1 second ago)
  Apply Lag:       0 seconds (computed 1 second ago)
  Apply Rate:      13.00 KByte/s
  Real Time Query: ON
  Instance(s):
    ORALIANGCE

Database Status:
SUCCESS

备库中的Transport Lag,Apply Lag是否正常

1.5 broker switcher切换

[ora11g@]$ dgmgrl
DGMGRL for Linux: Version 11.2.0.4.0 - 64bit Production

Copyright (c) 2000, 2009, Oracle. All rights reserved.

Welcome to DGMGRL, type "help" for information.
DGMGRL> connect sys
Password:
Connected.
DGMGRL> switchover to ORALIANGCEstd
Performing switchover NOW, please wait...
Operation requires a connection to instance "ORALIANGCE" on database "ORALIANGCEstd"
Connecting to instance "ORALIANGCE"...
Connected.
New primary database "ORALIANGCEstd" is opening...
Operation requires startup of instance "ORALIANGCE" on database "ORALIANGCE"
Starting instance "ORALIANGCE"...
ORACLE instance started.
Database mounted.
Database opened.
Switchover succeeded, new primary is "ORALIANGCEstd"
DGMGRL>

Broker会帮助你封装主备库实例启停,DG角色切换等命令

1.6 切换后检查

1.如RAC-RAC间切换,需要检查RAC各个节点是否启动

2.主备库数据字典检查
新主库:
SQL> select name,db_unique_name,database_role,open_mode from v$database;

NAME      DB_UNIQUE_NAME                 DATABASE_ROLE    OPEN_MODE
--------- ------------------------------ ---------------- --------------------
ORALIANGCE  ORALIANGCE                       PHYSICAL STANDBY READ ONLY WITH APPLY 

新备库:
SQL> select name,db_unique_name,database_role,open_mode from v$database;

SQL> set linesize 200 
SQL> select process,status,client_process,thread#,sequence#,block#,active_agents,known_agents from gv$managed_standby where process in ('LNS','RFS','MRP0') and  THREAD# <> 0;

PROCESS   STATUS       CLIENT_P    THREAD#  SEQUENCE#     BLOCK# ACTIVE_AGENTS KNOWN_AGENTS
--------- ------------ -------- ---------- ---------- ---------- ------------- ------------
RFS       IDLE         LGWR              1       6864        469             0            0
MRP0      APPLYING_LOG N/A               1       6864        469             5            5

3.alert日志检查:需要仔细检查主备库的alert日志中有无其他ORA报错,如使用HugePage,需要确认HugePage是否正确。

4.应用SERVICE监听注册情况

一则Bug导致数据库All Database Sessions Hang

春节前夕,一套核心交易系统出现短时间夯死的状况出现(后台数据库版本信息:Oracle 11.2.0.4 RAC 2节点,Linux X86服务器),活动会话数又飙升至近300+

20200127-1如上图所示,数据库从1月19日 09:34分左右开始,活动会话逐渐攀升,数据库在当时存在大量等待事件log file switch (checkpoint not complete),排查了硬件IO链路、应用事务量均正常,还是要在数据库软件层面进行分析。

    可以看到当时数据库活动会话概览,这些在等待log file switch (checkpoint incomplete)的会话均被节点2的1369会话所阻塞。

20200127-2

那么2节点的1369会话这时在干些什么?从ASH中看到,1369会话(LGWR)正在读取控制文件,等待事件为control file sequential read,但是这个动作是很快的动作,理论上不应该造成长时间的阻塞。

20200127-3

当时的DIAG进程做的HANGANALYZE中我们可以看到如下的Chain关系,开始试图找寻是否是Bug引起,因为种种客观现象实在是有悖常理,无法从原理上解释

20200127-4

从Oracle Mos上找寻相关Bug描述,果然有一个刚刚发布不久的Bug:

Bug 29635990 – All Database Sessions Hang Due To Checkpoint Incomplete (Doc ID
29635990.8)
20200127-5

但是这个Bug并未标注影响版本范围,但是和本次故障现象基本一致,遗憾的是并没有相关的Workrond并且此Bug只能在12.2版本中有相关Patch进行修复。

为了规避此问题的再次爆发,我们在数据库中设置了一个Job进行规避,调度时间按照redo 所有group#均变为ACTIVE且准备进行覆盖的时间周期,本系统为5分钟。

declare
jobno number;
begin dbms_job.submit(
jobno,
'begin
 execute immediate ''alter system checkpoint'';
end;',
sysdate,
'sysdate + 5/1440');
commit;
end;
/

每5分钟进行强制全量检查点,避免数据库再次产生log file switch (checkpoint not complete)的现象,从而导致产生更大数据库夯死风险。

删除空子表约束导致主表事务row cache lock/Library cache lock/Cursor pin s wait on x

春节前夕,公司一套核心核心再核心的数据库出现严重性能问题(版本信息:11.2.0.4),数据库活动会话飙升到300+,幸好当时处置得当,人员判断与应急迅速,及时kill了相关blocker session从而使得影响没有扩大。20200114-1从应用负责人员获悉,此时间段应用人员正在执行上线操作,具体操作为删除一张num rows=0的空表的外键约束。

alter table TRAVELSKYDBA drop constraint FK_TRAVELSKYDBA;

ASH中活动会话基本都在等待Library Cache Lock,Cursor Pin s Wait On X,Row Cache Lock上,阻塞情况如下:

20200123-11

继续分析,发现了一个更加奇怪的现象:

20200123-13

SESSION_ID=1827的会话为应用上线alter table删除外键约束的语句会话,SESSION_ID=73,2119,4000均为对删除外键的主表的正常业务DML语句(INSERT,DELETE,UPDATE),从ASH中看到1827会话正在等待正常业务事务(SESSION_ID=73)的LIBRARY CACHE LOCK,但是SESSION_ID=73在等 ROW CACHE LOCK,被ALTER TABLE (SESSION_ID=1827)阻塞,行成了死锁,并且ROW CACHE LOCK 的P1=8(dc_object与grants,dc_object),随后的正常事务的DML SQL想去软解析时遭遇Cursor Pin S wait on X。

从数据库DIAG进程自动dump的system state dump与Hanganalyze trace中确认,这些应用的SQL因为Rolling Invalidate Window Exceeded触发了硬解析,alter table 子表 drop constraints时,这项操作是需要申请主表DML游标Object Handle的Library Cache Lock的,主表涉及SQL在硬解析,ALTER TABLE求LIBRARY CACHE LOCK而不得被阻塞,但是主表DML硬解析申请ROW CACHE LOCK,理论上非常快速内存操作为何长时间不释放?产生死锁?并且Oracle并没有处理这个死锁

-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
 Oracle session identified by:
 {
 instance: 1 (#######)
 os id: 111552
 process id: 161, oracle@###-rac
 session id: 73
 session serial #: 181
 }
 is waiting for 'row cache lock' with wait info:
 {
 p1: 'cache id'=0x8
 p2: 'mode'=0x0
 p3: 'request'=0x3
 time in wait: 0.612302 sec
 heur. time in wait: 2 min 23 sec
 timeout after: 2.387698 sec
 wait id: 24235
 blocking: 286 sessions
 wait history:
 * time between current wait and wait #1: 0.000034 sec
 1. event: 'row cache lock'
 time waited: 3.000963 sec
 wait id: 24234 p1: 'cache id'=0x8
 p2: 'mode'=0x0
 p3: 'request'=0x3
 * time between wait #1 and #2: 0.000039 sec
 2. event: 'row cache lock'
 time waited: 3.000978 sec
 wait id: 24233 p1: 'cache id'=0x8
 p2: 'mode'=0x0
 p3: 'request'=0x3
 * time between wait #2 and #3: 0.000064 sec
 3. event: 'row cache lock'
 time waited: 3.000913 sec
 wait id: 24232 p1: 'cache id'=0x8
 p2: 'mode'=0x0
 p3: 'request'=0x3
 }
 and is blocked by
 => Oracle session identified by:
 {
 instance: 1 (*******)
 os id: 92902
 process id: 112, oracle@*****-rac
 session id: 1827
 session serial #: 19367
 }
 which is waiting for 'library cache lock' with wait info:
 {
 p1: 'handle address'=0xfeec0a948
 p2: 'lock address'=0xfe24600b8
 p3: '100*mode+namespace'=0x15dba00010003
 time in wait: 2 min 23 sec
 timeout after: 12 min 36 sec
 wait id: 1540
 blocking: 286 sessions
 wait history:
 * time between current wait and wait #1: 0.000150 sec
 1. event: 'gc current block 2-way'
 time waited: 0.000285 sec
 wait id: 1539 p1: ''=0x1
 p2: ''=0x131f3
 p3: ''=0x1
 * time between wait #1 and #2: 0.000131 sec
 2. event: 'gc current block 2-way'
 time waited: 0.000374 sec
 wait id: 1538 p1: ''=0x1
 p2: ''=0x131de
 p3: ''=0x1
 * time between wait #2 and #3: 0.002456 sec
 3. event: 'gc cr block 2-way'
 time waited: 0.000405 sec
 wait id: 1537 p1: ''=0x1
 p2: ''=0x131f3
 p3: ''=0x1
 }
 and is blocked by the session at the start of the chain.

Chain 1 Signature: 'library cache lock'<='row cache lock' (cycle)
Chain 1 Signature Hash: 0x52a8007d
----------------------------------------------------------------
并且 p3: '100*mode+namespace'=0x15dba00010003 --003 LOCK MODE=X

SQL> select to_number('15dba','xxxxxxx') from dual;
TO_NUMBER('15DBA','XXXXXXX')
---------------------------
 89530  --主表对象OBJECT_ID

20200123-16

SESSION_ID=73在sql net message from client中居然阻塞了1827的 alter table?

分析到这里,越来越感觉是Bug导致,从Mos上寻找相关案例发现一篇“现象相似”的文章,可惜版本无法对应上,不能确定是因为此Bug导致,虽然最后没有定位具体的Bug Number,但是此问题要告诫警示大家,不要再事务繁忙期间进行alter table DDL操作,虽然是一张空表,但是和其对象的相关OBJECT也存在受到牵连的可能性,从而产生跟大的影响。

20200123-17