Oracle Ebusiness Suite 11.5.10 Point In Time Recovery

Friday morning was not good for us. I got call around 8 a.m. and one of my colleagues informed me that “Debug instance post clone script” was run against Production database. Lot of production database tables was updated and it was not possible to rollback changes except restoring backup.

We take HP BC (Business Copy) backup every evening by 7.30. Before starting back up we generally pause database and initiate backup.

Whenever we get HP BC, we generally shutdown database and restart before copying BC backup set for database and applications clone.

We run database and applications servers on HP-UX 11 and discoverer server on Linux. I am not mentioning actual server names due to security concern.

We decided to use HP BC backup (taken at 7.30 p.m.) as restore and apply archive log file from 7.30 p.m. to 11.59 p.m. Our database size is close to 200G and we wanted to avoid copy time of 200G of data over Ethernet. We also planned to change server hostname from <dev_server> to <prod_db_servername> and put DNS entry. We decided all these to avoid production down time.

We took backup of existing HP BC copy (as of 7.30 p.m. Thursday) and performed following to recover database using point in time recovery (till 11.59 p.m.).

We performed following.

1. Copied HP BC database and applications to tape

2. Change archive log location in

log_archive_dest = /orastage/oracle/data/<sid>/

3. Copied password file from production DB server to development server when we wanted to recover production database $ORACLE_HOME/dbs/orapw<sid> to $ORACLE_HOME/dbs/

4. Copied $TNS_ADMIN/listener.ora, $TNS_ADMIN/tnsnames.ora files from production server to development server

5. Started production listener with same name and port on development server

Login as oracle

Set oracle environment

$export ORACLE_SID=<product_DB>

$export ORACLE_HOME=/local/oracle/product/9.2.0.8

$export TNS_ADMIN=$ORACLE_HOME/network/admin

$export PATH=$ORACLE_HOME/bin:$PATH

$lsnrctl start <production_listener>

6. Started database in nomount mode and performed following to recover database

Set environment as I mentioned above.

$sqlplus /nolog

SQL> connect / as sysdba

SQL> startup nomount

SQL> alter database mount

SQL> RECOVER DATABASE UNTIL TIME '2007-06-07:23:59:59' USING BACKUP CONTROLFILE;

ORA-00279: change 25163467125 generated at 06/08/2007 00:00:00 needed for thread 1

ORA-00289: suggestion : /orastage/oracle/data/<sid>/arch/8093_1.arc

ORA-00280: change 25 163 467 125 for thread 1 is in sequence #8093

It applied all log file and after apply last log file with sequence #8093 it failed with following error.

SQL> RECOVER DATABASE UNTIL TIME '2007-06-07:23:59:59' USING BACKUP CONTROLFILE

ORA-00279: change 25163467125 generated at 06/08/2007 00:00:00 needed for thread 1

ORA-00289: suggestion : /orastage/oracle/data/<sid>/arch/8093_1.arc

ORA-00280: change 25 163 467 125 for thread 1 is in sequence #8093

Specify log: {<RET>=suggested filename AUTO CANCEL}

/orastage/oracle/data/<sid>/arch/8093_1.arc

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: '/u03004.05/oracle/data/<sid>/system01.dbf'

Referred metalink note

Subject: DIAGNOSING ORA-1547 & ORA-1194 ERRORS DURING RECOVERY

Doc ID: Note:435201.1

Most of database data files were in fuzzy mode.

SQL> select file#,STATUS, FUZZY from v$datafile_header;

7. We concluded that backup was not good so we planned to restore Last week Sunday backup and apply all archive files.

8. We requested unix team to restore last Sunday’s cold backup.

9. Recover database from Sunday Cold backup set by apply all archive files (150)

Login as oracle and set environment Changed archive_log_destination parameter in $ORACLE_HOME/dbs/init<sid>.ora file to reflect new archive log file location.

log_archive_dest =/ORASTAGE/oracle/data/<sid>/arch

$sqlplus /nolog

SQL> connect / as sysdba

SQL> startup nomount

SQL> show parameter archive

SQL> show parameter archive

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

archive_lag_target integer 0

log_archive_dest string /ORASTAGE/oracle/data/<sid>/arch

SQL> RECOVER DATABASE UNTIL TIME '2007-06-07:23:59:59' USING BACKUP CONTROLFILE;

AUTO

Content from $bdump/alert<sid>.log file.

Sat Jun 9 11:48:15 2007

Database mounted in Exclusive Mode.

Completed: ALTER DATABASE MOUNT

Sat Jun 9 11:49:19 2007

ALTER DATABASE RECOVER DATABASE UNTIL TIME '2007-06-07:23:59:59' USING BACKUP CONTROLFILE

Sat Jun 9 11:49:19 2007

Media Recovery Start

ORA-279 signalled during: ALTER DATABASE RECOVER DATABASE UNTIL TIME '2007-...

Sat Jun 9 11:49:48 2007

ALTER DATABASE RECOVER CONTINUE DEFAULT

Sat Jun 9 11:49:48 2007

Media Recovery Log /ORASTAGE/oracle/data/<sid>/arch/7943_1.arc

.

.

.

ALTER DATABASE RECOVER CONTINUE DEFAULT

Sat Jun 9 20:30:28 2007

Media Recovery Log /ORASTAGE/oracle/data/<sid>/arch/8093_1.arc

.

.

.

Sat Jun 9 20:34:17 2007

Terminal Recovery: done UNTIL CHANGE 25163467125

Media Recovery Complete

Completed: ALTER DATABASE RECOVER CONTINUE DEFAULT

Sat Jun 9 20:34:21 2007

ARC1: Cannot archive online log based on backup controlfile

Sat Jun 9 20:35:21 2007

ARC1: Cannot archive online log based on backup controlfile

Sat Jun 9 20:36:14 2007

SQL> ALTER DATABASE OPEN RESETLOGS;

ALTER DATABASE OPEN RESETLOGS

Sat Jun 9 20:36:14 2007

RESETLOGS after incomplete recovery UNTIL CHANGE 25163467125

Resetting resetlogs activation ID 1687126238 (0x648f80de)

Sat Jun 9 20:39:02 2007

.

.

Sat Jun 9 20:44:25 2007

replication_dependency_tracking turned off (no async multimaster replication found)

Completed: ALTER DATABASE OPEN RESETLOGS

It took almost 9 hour to apply 150 archive file (size 300M).

10. Started database listener and did basic checking to validate database restore and recovery.

11. Logged in as applmgr and tried to start oracle application services as given below

$ . $APPL_TOP/APPSORA.env

$ cd $COMMON_TOP/admin/scripts/<sid>_<hostname>/

$adstrtal.sh apps/<password>

It started all services.

I tried to log in to applications using given URL.

http://<hostname>.<domainname>:<PORT>/

Click on “Apps Logon Links”

Click on “E-Business Home Page”

Logged as “SYSADMIN” user

Login failed with given error.

"YOU HAVE ENCOUNTERED AN UNEXPECTED ERROR"

As part of troubleshooting I did following.

1. Gave wrong password and it failed with authentication error.

http://<hostname>.<domainname>:<PORT>/OA_HTML/jsp/fnd/aoljtest.jsp

All AOLJ test was passed except jsp pages. We doubt problem could be with jsp pages

2. Turned on debug for Apache and JSP as given below

a. Stopped apache services

$apps/OEBS/ndev2/commontop/admin/scripts/<sid>_<hostname>/adapcctl.sh stop

b. Deleted $IAS_ORACLE_HOME/Apache/Apache/logs and $IAS_ORACLE_HOME/Apache/Jserv/log

c. Edited $IAS_ORACLE_HOME/Apache/Apache/conf/httpd.conf

LogLevel debug

d. Edited $IAS_ORACLE_HOME/Apache/Jserv/conf/jserv.conf

ApJServLogLevel debug

e. Edited $IAS_ORACLE_HOME/Apache/Jserv/conf/jserv.properties

log=true

Notice following error

$IAS_ORACLE_HOME/Apache/Jserv/logs/ mod_jserv.log

[10/06/2007 12:59:36:265] (ERROR) ajp12: Servlet Error: OracleJSP: java.io.FileNotFoundException

$IAS_ORACLE_HOME/Apache/Jserv/logs/jserv.log

[10/06/2007 12:26:43:744 EDT] oracle.jsp.JspServlet: init

[Jun 10, 2007 12:27:04 PM EDT]:1181492824137:Thread[Thread-70,10,main]:-1:-1:hostname.domain name:<ipaddress>:8102:16020:UNEXPECTED:[fnd.common.logging.DebugEventManager.handlerException]

:java.lang.Exception: /aferror.log (Permission denied (errno:13))

at oracle.apps.fnd.common.logging.FileHandler.<init>(FileHandler.java:103)

at oracle.apps.fnd.common.logging.FileHandler.<init>(FileHandler.java:80)

at oracle.apps.fnd.common.logging.DebugEventManager.registerHandlers(DebugEventManager.java:

1241)

at oracle.apps.fnd.common.logging.DebugEventManager.init(DebugEventManager.java:904)

at oracle.apps.fnd.common.logging.DebugEventManager.<init>(DebugEventManager.java:194)

at oracle.apps.fnd.common.AppsLog.<init>(AppsLog.java:519)

at oracle.apps.fnd.common.AppsLog.<init>(AppsLog.java:489)

at oracle.apps.fnd.common.AppsLog.<clinit>(AppsLog.java:469)

at oracle.apps.fnd.common.AppsContext.makeLog(AppsContext.java:1153)

at oracle.apps.fnd.common.Context.setLog(Context.java:1400)

at oracle.apps.fnd.common.Context.setLog(Context.java:1381)

at oracle.apps.fnd.common.Context.getLog(Context.java:1353)

at oracle.apps.fnd.common.Context.isLoggingEnabled(Context.java:2119)

at oracle.apps.fnd.common.Context.makeConnectionManager(Context.java:655)

at oracle.apps.fnd.common.AppsContext.makeConnectionManager(AppsContext.java:1186)

at oracle.apps.fnd.common.Context.setConnectionManager(Context.java:615)

at oracle.apps.fnd.common.Context.setConnectionManager(Context.java:599)

at oracle.apps.fnd.common.AppsContext.initializeContext(AppsContext.java:880)

at oracle.apps.fnd.common.AppsContext.<init>(AppsContext.java:742)

at oracle.apps.mwa.container.ApplicationsObjectLibrary.AOLInit(ApplicationsObjectLibrary.jav

a:174)

at oracle.apps.mwa.container.ApplicationsObjectLibrary.<init>(ApplicationsObjectLibrary.java

:78)

at oracle.apps.mwa.container.MWALib.setObjectLibrary(MWALib.java:339)

at oracle.apps.mwa.wap.engine.WapServlet.init(WapServlet.java:158)

at org.apache.jserv.JServServletManager.load_init(JServServletManager.java:755)

at org.apache.jserv.JServServletManager.loadServlet(JServServletManager.java:659)

at org.apache.jserv.JServServletManager.loadStartupServlets(JServServletManager.java:789)

at org.apache.jserv.JServServletManager.init(JServServletManager.java:447)

at org.apache.jserv.JServ.start(JServ.java:625)

at org.apache.jserv.JServ.main(JServ.java:234)

12. I got a hit and executed give below as advised by this metalink note.

Run the following to synchronize WF tables.

Begin

apps.wf_local_synch.BULKSYNCHRONIZATION (P_ORIG_SYSTEM=>'ALL',

P_PARALLEL_PROCESSES=>2,

P_LOGGING=>'LOGGING',

P_RAISEERRORS=>TRUE, P_TEMPTABLESPACE=>'APPS_TS_TX_DATA');

END;

/

Reference :

Unable To Login After Clone

Doc ID: Note:418130.1

It was verified by functional team and then we good database and applications backup before releasing production server for regular use.

Noteà Due to security Concern I have not mentioned actual server name, domain name, ipaddress and ORACLE SID.