I encountered a strange error recently that I think is worth documenting.
In our production environment, we began to have issues running adop phase=fs_clone. The strange thing was it only happened in production. A clone of production to another environment had no issues running fs_clone.
adop would complete the FSCloneStage, begin FSCloneApply and end in an error.
FUNCTION: main::runFSCloneApply [ Level 1 ]
ERRORMSG: /u01/app/oracle/apps/fs2/EBSapps/comn/adopclone_appr12prd/bin/adclone.pl did not go through successfully.
The logs we care about for fs_clone are in fs_ne/EBSapps/log/NN/YYYYMMDD_HHMISS/fs_clone/host/TXK_SYNC_CREATE where NN is the adop session, YYYYMMDD_HHMISS is the date time stamp, and host is the short hostname. The first step is to look at txkADOPPreparePhaseSynchronize.log to see the details of what is happening. Look for EXIT STATUS: with nonzero values, and then lock at the associated logs. For example,
Copying the directory
———————
SOURCE : /u01/app/oracle/apps/fs2/EBSapps/comn/util
TARGET : /u01/app/oracle/apps/fs1/EBSapps/comn/util
Execute SYSTEM command : cp -rH/u01/app/oracle/apps/fs2/EBSapps/comn/util /u01/app/oracle/apps/fs1/EBSapps/comn/util
EXIT STATUS: 1
Copied /u01/app/oracle/apps/fs2/EBSapps/comn/util into /u01/app/oracle/apps/fs1/EBSapps/comn/utilLOG FILE: /u01/app/oracle/apps/fs_ne/EBSapps/log/adop/75/20180912_001320/fs_clone/appr12prd/TXK_SYNC_create/cp_rH.out
Unfortunately, this log will not be much help as ls -l shows
-rw-r–r– 1 oracle oinstall 0 Sep 12 00:22 cp_rH.out
If this was a file permission issue, we should find the evidence here.
In this case, the major clue is actually back in FSCloneStage even though it completed and progressed to FSCloneApply.
EXIT STATUS: 0
***** W A R N I N G *****
/u01/app/oracle/apps/fs2/FMW_Home/Oracle_EBS-app1/oui/bin/runInstaller -detachhome -silent ORACLE_HOME=/u01/app/oracle/apps/fs1/FMW_Home/Oracle_EBS-app1 -invPtrLoc /etc/oraInst.loc -debug -jreLoc /u01/app/oracle/apps/fs2/FMW_Home/Oracle_EBS-app1/jdk returned FAILURE status.
Either ORACLE_HOME=/u01/app/oracle/apps/fs1/FMW_Home/Oracle_EBS-app1 is already detached or issue with inventory.
Proceeding further. Issues will be reported when actual cloning starts.
LOG FILE: /u01/app/oracle/apps/fs_ne/EBSapps/log/adop/75/20180912_001320/fs_clone/appr12prd/TXK_SYNC_create/Oracle_EBS-app1_detachHome.out.
Creating the directory: /u01/app/oracle/apps/fs1/FMW_Home/webtier
Execute SYSTEM command : /u01/app/oracle/apps/fs2/FMW_Home/webtier/oui/bin/runInstaller -detachhome -silent ORACLE_HOME=/u01/app/oracle/apps/fs1/FMW_Home/webtier -invPtrLoc /etc/oraInst.loc -debug
Even worse, this is an EXIT STATUS: 0. Since the issue could be that the home is already detached from the central inventory, it has to accept this failure. Unfortunately this was not the case for us. Looking at the log Oracle_EBS-app1_detachHome.out we find
Starting Oracle Universal Installer…
Checking swap space: 389 MB available, 500 MB required.Failed <<<<
Some requirement checks failed. You must fulfill these requirements before
continuing with the installation,
Exiting Oracle Universal Installer, log for this session can be found at /u01/app/oracle/oraInventory/logs/DetachHome2018-09-12_12-22-18AM.log
Looking at top and/proc/swaps, I realized that swap was undersized for this server. The impact of this was that when the FSCloneApply stage tried to register the oracle home, it failed (same swap issue plus it was never removed). As soon as swap space was added to the server, adop phase=fs_clone force=yes was able to complete (if fs_clone fails, restart with force=yes to make it start from the beginning).
Have you had any unusual failures with fs_clone? If so, let me know in the comments.