Below error persists for one database during SYNC operation:RMAN> resync catalog;
starting full resync of recovery catalog
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03009: failure of resync command on default channel at 11/05/2012 07:10:03
RMAN-20052: invalid datafile create SCN
Target DB version:
11.2.0.2.6
Catalog DB version:
11.2.0.2.6
Catalog schema version:
catalog > Select * from rcver ;
VERSION
------------
11.02.00.03
After compare between target and catalog, found the create_scn for all datafiles and tempfiles are SYNC in both DB:CATALOG DB:
catalog > select file#,CREATION_CHANGE# from RC_DATAFILE where DB_NAME='ATPPSS' order by 1;
FILE# CREATION_CHANGE#
---------- ----------------
1 7
2 2178
3 969548
4 18151
5 1002153
6 1053956
7 1054333
8 1501572
9 1502015
10 1506616
11 1515561
12 1516921
13 5361004
14 5779799
14 rows selected.
TARGET DB:
target > select file#,CREATION_CHANGE# from v$datafile;
FILE# CREATION_CHANGE#
---------- ----------------
1 7
2 2178
3 969548
4 18151
5 1002153
6 1053956
7 1054333
8 1501572
9 1502015
10 1506616
11 1515561
12 1516921
13 5361004
14 5779799
14 rows selected.
After debug rman session, we can see the error report when doing DBMS_RCVCAT.CHECKDATAFILE on file# 13:DBGRPC: krmxrpc - channel default kpurpc2 err=0 db=rcvcat proc=RMANADMIN.DBMS_RCVCAT.CHECKDATAFILE excl: 0
DBGRCVCAT: checkDatafile - size changed for file#: 12 from 131072 to 153600
DBGRCVCAT: incResynActions - Not debugging
DBGRCVCAT: setCloneName: file#=12, creation_fname=1516921, plugin_change#=0, old_clone_fname=, new_clone_fname=NONE
DBGRESYNC: channel default: Resyncing datafile +DATA/atppss/datafile/example.3079.785280031 [23:38:41.110] (resync)
DBGRESYNC: channel default: Calling checkDataFile for fileno 13 size 131072 [23:38:41.110] (resync)
DBGRPC: krmxrpc - channel default kpurpc2 err=20052 db=rcvcat proc=RMANADMIN.DBMS_RCVCAT.CHECKDATAFILE excl: 97
DBGRPC: krmxrpc - channel default kpurpc2 err=0 db=rcvcat proc=RMANADMIN.DBMS_RCVCAT.CANCELCKPT excl: 0
DBGRCVCAT: cancelCkpt - rollback, released all locks
DBGRPC: krmxrpc - channel default kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.CFILEUSECURRENT excl: 0
Below is the defination for 20052 in DBMS_RCVCAT.CHECKDATAFILE:PROCEDURE CHECKDATAFILE()
IF (plugged_readonly = 'NO' AND create_scn > this_ckp_scn) THEN
raise_application_error(-20052, 'Invalid datafile create SCN');
ELSIF (plugged_readonly = 'YES' AND plugin_scn > this_ckp_scn) THEN
raise_application_error(-20055, 'Invalid datafile plugin SCN');
END IF;
...........
IF (create_scn = dfRec.create_scn AND
plugin_scn = dfRec.plugin_scn) THEN
...........
ELSIF ((case when plugged_readonly = 'NO' then
create_scn else plugin_scn end) >
(case when dfRec.plugged_readonly = 'NO' then
dfRec.create_scn else dfRec.plugin_scn end)) THEN
...........
ELSE -- (create_scn < dfRec.create_scn)
-- The client passed us a create SCN for this datafile that is
-- less than the SCN in the rcvcat. I.e., the target database
-- controlfile now contains a previous incarnation of this datafile.
-- This can happen only if the user has some old controlfile, or
-- has done a resetlogs and not told us about it.
IF (plugged_readonly = 'NO') THEN
raise_application_error(-20052, 'Invalid datafile create SCN');
ELSE
raise_application_error(-20055, 'Invalid datafile plugin SCN');
END IF;
END IF;
All the judgement done by three argument: plugin_scn, plugged_readonly,create_scn. Let's check above three values in both target DB and catalog DB: CATALOG DB:
catalog > select CREATE_SCN,PLUGGED_READONLY,PLUGIN_SCN from df where DBINC_KEY='3199420' and FILE# =13;
CREATE_SCN PLU PLUGIN_SCN
---------- --- ----------
5361004 NO 992188
TARGET DB:
target > select CREATION_CHANGE#,PLUGGED_READONLY,PLUGIN_CHANGE# from v$datafile where file#=13;
CREATION_CHANGE# PLU PLUGIN_CHANGE#
---------------- --- --------------
5361004 NO 0
Now we can clearly see that red part's differ is the reason we got the error.
Since pluggable-DB is a new feature in 12c, and not published in any current version as yet.
So currently all databases’ all datafiles’ PLUGIN_CHANGE# should be 0.
The PLUGIN_SCN is 992188 in CATALOG DB is obviously not correct. Un-Register/Re-register the DB in catalog may or may not help to solve this issue.
More......
GE, AGFA. experienced in 9i/10g/11g/12c, AdvanceReplication, Stream, GoldenGate, RAC, DataGuard, ODA, EXADATA, GridControl. In my career I have always been assigned to handle most complicated and critical oracle issues without solution online, and I hope to record some of them via this blog.
November 5, 2012
DEBUG RMAN: "RMAN-20052: invalid datafile create SCN" due to PLUGIN_SCN out of SYNC
September 12, 2012
CSSD terminated from clssnmvDiskPingMonitorThread without disk timeout countdown
One node's cluster suddenly terminated.
Below is the message in cluster's alert.log：
2012-09-11 11:41:30.328
[ctssd(22428)]CRS-2409:The clock on host node8 is not synchronous with the mean cluster time. No action has been taken as the Cluster Time Synchroniza
tion Service is running in observer mode.
2012-09-11 12:30:03.122
[cssd(21061)]CRS-1606:The number of voting files available, 0, is less than the minimum number of voting files required, 1, resulting in CSSD termination to
ensure data integrity; details at (:CSSNM00018:) in /prod/grid/11.2.0/grid/log/node8/cssd/ocssd.log
2012-09-11 12:30:03.123
[cssd(21061)]CRS-1656:The CSS daemon is terminating due to a fatal error; Details at (:CSSSC00012:) in /prod/grid/11.2.0/grid/log/node8/cssd/ocssd.log
2012-09-11 12:30:03.233 [cssd(21061)]CRS-1652:Starting clean up of CRSD resources.
Let‘s check ocssd.log：
2012-09-11 12:30:02.543: [ CSSD][1113450816]clssnmSendingThread: sending status msg to all nodes
2012-09-11 12:30:02.543: [ CSSD][1113450816]clssnmSendingThread: sent 5 status msgs to all nodes
2012-09-11 12:30:03.122: [ CSSD][1082489152](:CSSNM00018:)clssnmvDiskCheck: Aborting, 0 of 1 configured voting disks available, need 1
2012-09-11 12:30:03.123: [ CSSD][1082489152]###################################
2012-09-11 12:30:03.123: [ CSSD][1082489152]clssscExit: CSSD aborting from thread clssnmvDiskPingMonitorThread
2012-09-11 12:30:03.123: [ CSSD][1082489152]###################################
2012-09-11 12:30:03.123: [ CSSD][1082489152](:CSSSC00012:)clssscExit: A fatal error occurred and the CSS daemon is terminating abnormally
So it looks like an IO issue to VOTEDISK.
But after checking we didn't find any abnormal or error message from neither OS level nor storage side.
Then i reviewed the ocssd.log, and with surprise i found there is no long-disk timeout countdown in log.
We know if ocssd failed to reach Votedisk, then it will start to count 200s. Only if after 200s the votedisk still unavailable, then occsd will terminated itself.
The countdown information should be like:
clssscMonitorThreads clssnmvDiskPingThread not scheduled for 16020 msecs
But in our case, there is not such countdown, the occssd just terminated from clssnmvDiskPingMonitorThread all of a sudden.
It should be a bug instead of VOTEDISK IO issue. I will raise an SR with oracle support for further checking.
More......