Oracle…sometimes blinding in complexity, and a foreshadowing of what happens when a system becomes so complex that it becomes fragile.
This is what the screen session looks like:
adnodemgrctl.sh: check the logfile /u01/oradev/fs1/inst/apps/DEV2_itsrv33m/logs/appl/admin/log/adnodemgrctl.txt for more information …
[UNEXPECTED]fs_clone has failed.
[STATEMENT] Please run adopscanlog utility, using the command
“adopscanlog -latest=yes”
to get the list of the log files along with snippet of the error message corresponding to each log file.
adop exiting with status = 2 (Fail)
Here is what it looks like in the adop.log
[EVENT] Performing CLONE steps.
[PROCEDURE] [START 2016/11/08 08:20:19] CLONE Patch File System from Run File System
[PROCEDURE] Calling: /u01/oradev/fs2/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl
[EVENT] Log: /u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m
[UNEXPECTED]Error occurred running “perl /u01/oradev/fs2/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl -contextfile=/u01/oradev/fs2/inst/apps/DEV2_itsrv33m/appl/admin/DEV2_itsrv33m.xml -patchcontextfile=/u01/oradev/fs1/inst/apps/DEV2_itsrv33m/appl/admin/DEV2_itsrv33m.xml -promptmsg=hide -console=off -mode=create -sync_mode=copy -sessionid=25 -timestamp=20161108_081645 -outdir=/u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m”
[UNEXPECTED]occurred during CLONE Patch File System from Run File System, running command: “perl /u01/oradev/fs2/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl -contextfile=/u01/oradev/fs2/inst/apps/DEV2_itsrv33m/appl/admin/DEV2_itsrv33m.xml -patchcontextfile=/u01/oradev/fs1/inst/apps/DEV2_itsrv33m/appl/admin/DEV2_itsrv33m.xml -promptmsg=hide -console=off -mode=create -sync_mode=copy -sessionid=25 -timestamp=20161108_081645 -outdir=/u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m”.
[EVENT] Releasing managed server ports.
[PROCEDURE] [START 2016/11/08 08:30:55] Releasing ports
[STATEMENT] Calling task: “Releasing ports on itsrv33m”; script: “/u01/oradev/fs2/inst/apps/DEV2_itsrv33m/admin/install/txkCloneAcquirePort.pl”; args: ” -option=close -server=itsrv33m.mwd.h2o -ports=5570,7015,7615,7415,7215,7216,7217,7815,6114,6214,10013 -log=/u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/txkCloneAcquirePort.log”
[PROCEDURE] [START 2016/11/08 08:30:56] Releasing ports on itsrv33m
[PROCEDURE] Calling: /u01/oradev/fs2/inst/apps/DEV2_itsrv33m/admin/install/txkCloneAcquirePort.pl
[EVENT] Log: /u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/txkCloneAcquirePort.log
[PROCEDURE] [END 2016/11/08 08:30:57] Releasing ports on itsrv33m
[PROCEDURE] [END 2016/11/08 08:30:57] Releasing ports
How cryptic! Looks complicated. This system happens to have AD/TXK.Delta.8, so the logs related to adop are all being centralized under the session # (in this case “25”.)
Diving deep into the log subdirectories:
/u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/TXK_SYNC_create/txkADOPPreparePhaseSynchronize.log
================================
Inside copyComnUtil()…
================================
Directory /u01/oradev/fs1/EBSapps/comn already exists.
Removing the directory: /u01/oradev/fs1/EBSapps/comn/util
Copying the directory
———————
SOURCE : /u01/oradev/fs2/EBSapps/comn/util
TARGET : /u01/oradev/fs1/EBSapps/comn/util
Execute SYSTEM command : cp -rH /u01/oradev/fs2/EBSapps/comn/util /u01/oradev/fs1/EBSapps/comn/util
EXIT STATUS: 1
Copied /u01/oradev/fs2/EBSapps/comn/util into /u01/oradev/fs1/EBSapps/comn/utilLOG FILE: /u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/TXK_SYNC_create/cp_rH.out
<snip>
======================================
Inside copyCloneLogsToFSNE()…
======================================
Creating the directory: /u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/TXK_SYNC_create/fsclone_apply
Copying the directory
———————
SOURCE : /u01/oradev/fs2/inst/apps/DEV2_itsrv33m/admin/log/clone
TARGET : /u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/TXK_SYNC_create/fsclone_apply
/u01/oradev/fs2/EBSapps/comn/adopclone_itsrv33m/bin/adclone.pl did not go through successfully.
LOG DIRECTORY: /u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/TXK_SYNC_create/fsclone_apply.
*******FATAL ERROR*******
PROGRAM : (/u01/oradev/fs2/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl)
TIME : Tue Nov 8 08:30:55 2016
FUNCTION: main::runFSCloneApply [ Level 1 ]
ERRORMSG: /u01/oradev/fs2/EBSapps/comn/adopclone_itsrv33m/bin/adclone.pl did not go through successfully.
/u01/oradev/fs_ne/EBSapps/log/adop/25/20161108_081645/fs_clone/itsrv33m/TXK_SYNC_create/fsclone_apply/FSCloneApplyAppsTier_11080821.log
(One innocuous, but annoying file, owned by someone other than applmgr, and happened to be 600 (user read/write only):)
Done copying /u01/oradev/fs2/EBSapps/appl/wms to /u01/oradev/fs1/EBSapps/appl/wms/
Copying /u01/oradev/fs2/EBSapps/appl/gmf to /u01/oradev/fs1/EBSapps/appl/gmf/
WARNING:
.end std out.
cp: cannot open /u01/oradev/fs2/EBSapps/appl/mwd/12.0.0/sql/MWDPOLPO.xsl: Permission denied
.end err out.
WARNING: Copying of /u01/oradev/fs2/EBSapps/appl/mwd failed
ERROR: Copying failed, so stopping all the parallel threads
Done copying /u01/oradev/fs2/EBSapps/appl/okc to /u01/oradev/fs1/EBSapps/appl/okc/
WARNING: Copying of /u01/oradev/fs2/EBSapps/appl/okc failed
Done copying /u01/oradev/fs2/EBSapps/comn/java/classes/oracle/apps/pqh to /u01/oradev/fs1/EBSapps/comn/java/classes/oracle/apps/pqh/
WARNING: Copying of /u01/oradev/fs2/EBSapps/comn/java/classes/oracle/apps/pqh failed
Done copying /u01/oradev/fs2/EBSapps/appl/gmf to /u01/oradev/fs1/EBSapps/appl/gmf/
WARNING: Copying of /u01/oradev/fs2/EBSapps/appl/gmf failed
Done copying /u01/oradev/fs2/EBSapps/comn/java/classes/oracle/apps/ies to /u01/oradev/fs1/EBSapps/comn/java/classes/oracle/apps/ies/
WARNING: Copying of /u01/oradev/fs2/EBSapps/comn/java/classes/oracle/apps/ies failed
Done copying /u01/oradev/fs2/EBSapps/appl/msc to /u01/oradev/fs1/EBSapps/appl/msc/
WARNING: Copying of /u01/oradev/fs2/EBSapps/appl/msc failed
Done copying /u01/oradev/fs2/EBSapps/appl/ams to /u01/oradev/fs1/EBSapps/appl/ams/
WARNING: Copying of /u01/oradev/fs2/EBSapps/appl/ams failed
Done copying /u01/oradev/fs2/EBSapps/appl/cs to /u01/oradev/fs1/EBSapps/appl/cs/
WARNING: Copying of /u01/oradev/fs2/EBSapps/appl/cs failed
START: Inside exitClone….
Updating status INCOMPLETE for ApplyApplTop
START: Updating status INCOMPLETE for action ApplyApplTop
END: Updated status INCOMPLETE for action ApplyApplTop
One file. A single file. Could have been a hidden file. Could have been anywhere in the entire AppsTier filesystem. This one file stopped ADOP cold from performing. This happened to be phase=fs_clone, but could have been a patching session, or a post-clone config (adcfgclone.pl) session.
Remove the file, and:
The fs_clone phase completed successfully.
adop exiting with status = 0 (Success)
Complexity leads to unintentional fragility.
Thoughts from James H. Lui 
Hi –
I wonder if this permissions error could have also been from running fs_clone phase while you are in the patch file system. fs_clone can fail if running it while sitting in patch file system, since the patch file system structure and directories are changing, if you are in one of the folders or subfolder that needs to be moved or deleted then a permission error is raised because it can’t do that while we are sitting in the patch file system.
After you had performed your diagnosis is it possible that you then ran fs_clone outside of the patch file system and therefore it then worked?
I realize this is old posting, but I mention this now because I just ran into it this morning.
In this example, FS1 was Run, and FS2 was Patch. And yes, you can’t run an adop from inside the Patch filesystem without more errors. But that wasn’t this case. It simply was related to the file permissions for the single file not being read/write by the applmgr account.