FS_CLONE Fails With java.lang.Exception: Unable to get free port for server.

After applying R12.AD.C.Delta.9 and R12.TXK.C.Delta.9 in our EBS instance, Below error occured while doing fs_clone.

$ adop phase=fs_clone fails

adop.log shows:

[EVENT] Running fs_clone on admin node: [<node_name>].

..

[ERROR] Node: "<node_name>" Status: "failed"

[ERROR] adop phase=fs_clone failed on Node: "<node_name>"

[UNEXPECTED]Error occurred running "perl /data02/app/applmgr/122/instance/fs1/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl -contextfile=/data02/app/applmgr/122/instance/fs1/inst/apps/instance_<node_name>/appl/admin/instance_<node_name>1.xml -patchcontextfile=/data02/app/applmgr/122/instance/fs2/inst/apps/instance_<node_name>/appl/admin/instance_<node_name>.xml -promptmsg=hide -console=off -mode=create -sync_mode=copy -sessionid=42 -timestamp=20170622_155032 -outdir=/data02/app/applmgr/122/instance/fs_ne/EBSapps/log/adop/42/20170622_155032/fs_clone/<node_name>"

[UNEXPECTED]occurred during CLONE Patch File System from Run File System, running command: "perl /data02/app/applmgr/122/instance/fs1/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl -contextfile=/data02/app/applmgr/122/instance/fs1/inst/apps/instance_<node_name>/appl/admin/instance_<node_name>.xml -patchcontextfile=/data02/app/applmgr/122/instance/fs2/inst/apps/instance_<node_name>/appl/admin/instance_<node_name>.xml -promptmsg=hide -console=off -mode=create -sync_mode=copy -sessionid=42 -timestamp=20170622_155032 -outdir=/data02/app/applmgr/122/instance/fs_ne/EBSapps/log/adop/42/20170622_155032/fs_clone/<node_name>".

fs_clone/node-prod-01/TXK_SYNC_create/txkADOPPreparePhaseSynchronize.log shows:

======================================

Inside copyCloneLogsToFSNE()...

======================================

Creating the directory: /data02/app/applmgr/122/instance/fs_ne/EBSapps/log/adop/42/20170622_155032/fs_clone/<node_name>/TXK_SYNC_create/fsclone_apply

Copying the directory

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

SOURCE : /data02/app/applmgr/122/instance/fs1/inst/apps/instance_<node_name>/admin/log/clone

TARGET : /data02/app/applmgr/122/instance/fs_ne/EBSapps/log/adop/42/20170622_155032/fs_clone/<node_name>/TXK_SYNC_create/fsclone_apply

/data02/app/applmgr/122/instance/fs1/EBSapps/comn/adopclone_<node_name>/bin/adclone.pl did not go through successfully.

LOG DIRECTORY: /data02/app/applmgr/122/instance/fs_ne/EBSapps/log/adop/42/20170622_155032/fs_clone/<node_name>/TXK_SYNC_create/fsclone_apply.

*******FATAL ERROR*******

PROGRAM : (/data02/app/applmgr/122/instance/fs1/EBSapps/appl/ad/12.0.0/patch/115/bin/txkADOPPreparePhaseSynchronize.pl)

TIME : Thu Jun 22 16:30:37 2017

FUNCTION: main::runFSCloneApply [ Level 1 ]

ERRORMSG: /data02/app/applmgr/122/instance/fs1/EBSapps/comn/adopclone_<node_name>/bin/adclone.pl did not go through successfully.

/fs_clone/<node_name>/TXK_SYNC_create/fsclone_apply/FSCloneApplyAppsTier_06221627.log shows:

END: Created backup...

Backup applications domain directory if exists

Directory /data02/app/applmgr/122/<sid>/fs2/FMW_Home/user_projects/applications/EBS_domain_<sid> does not exist.

START: Creating new WLS domain.

Running /data02/app/applmgr/122/<sid>/fs2/FMW_Home/oracle_common/bin/pasteConfig.sh -javaHome /data02/app/applmgr/122/<sid>/fs2/EBSapps/comn/util/jdk -al /data02/app/applmgr/122/<sid>/fs1/EBSapps/comn/adopclone_<node_name>/FMW/WLS/EBSdomain.jar -tdl /data02/app/applmgr/122/<sid>/fs2/FMW_Home/user_projects/domains/EBS_domain_<sid> -tmw /data02/app/applmgr/122/<sid>/fs2/FMW_Home -mpl /data02/app/applmgr/122/<sid>/fs1/EBSapps/comn/adopclone_<node_name>/FMW/WLS/plan/moveplan.xml -ldl /data02/app/applmgr/122/<sid>/fs1/inst/apps/<sid>_<node_name>1/admin/log/clone/wlsT2PApply -silent true -debug true -domainAdminPassword /data02/app/applmgr/122/<sid>/fs1/EBSapps/comn/adopclone_<node_name>/FMW/tempinfo.txt

Script Executed in 169799 milliseconds, returning status 255

ERROR: Script failed, exit code 255

START: Inside exitClone....

Updating status INCOMPLETE for ApplywlsTechStack

START: Updating status INCOMPLETE for action ApplywlsTechStack

END: Updated status INCOMPLETE for action ApplywlsTechStack

/fs_clone/<node_name>/TXK_SYNC_create/fsclone_apply/wlsT2PApply/CLONE2017-06-22_16-27-46_1106077216.log shows:

FINE : Jun 22, 2017 16:30:34 - [PortUtil:isPortAvailable] Port 5047 reserved: From the port range 5001-5050 by server oafm_server13

FINE : Jun 22, 2017 16:30:34 - [PortUtil:isPortAvailable] Port 5048 reserved: From the port range 5001-5050 by server forms-c4ws_server13

FINE : Jun 22, 2017 16:30:34 - [PortUtil:isPortAvailable] Port 5049 reserved: From the port range 5001-5050 by server oacore_server14

FINE : Jun 22, 2017 16:30:34 - [PortUtil:isPortAvailable] Port 5050 reserved: From the port range 5001-5050 by server forms_server14

FINE : Jun 22, 2017 16:30:34 - [J2EEGenericValidationUtil:getTemporaryPortFromPortRange] Unable to get free port for server oafm_server14 from port range 5001-5050

FINE : Jun 22, 2017 16:30:34 - [CloneLogger:unSetSystemOutErrToCloneLogger] Invoking unsetSystemOutErrToCloneLogger 1

FINE : Jun 22, 2017 16:30:34 - [CloneLogger:unSetSystemOutErrToCloneLogger] Invoking unsetSystemOutErrToCloneLogger 2

FINE : Jun 22, 2017 16:30:34 - CLONE-22264 Time taken to restore sourceid "J2EECOMPONENT@EBS_domain_ebsprod" is "141,611" milliseconds.

FINE : Jun 22, 2017 16:30:34 - [ApplyCloneRequest:applyArchive] One cloner object was not executed properly, so rest were not executed.

INFO : Jun 22, 2017 16:30:34 - CLONE-21037 Time taken to restore all cloners from archive was "141" seconds.

INFO : Jun 22, 2017 16:30:34 - CLONE-21006 Total time taken by T2P process was 141 seconds.

INFO : Jun 22, 2017 16:30:34 - CLONE-21276

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

T2P Summary Begin

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

Error Message :1

Jun 22, 2017 16:30:34 - SEVERE - CLONE-20937 "pasteConfig" operation of J2EE domain failed. Check clone log and error files for more details.

Error Message :2

Jun 22, 2017 16:30:34 - ERROR - CLONE-20237 Restoring the sourceid "J2EECOMPONENT@EBS_domain_ebsprod" has failed.

Jun 22, 2017 16:30:34 - CAUSE - CLONE-20237 An internal operation failed.

Jun 22, 2017 16:30:34 - ACTION - CLONE-20237 Check the clone log for more details.

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

T2P Summary End

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

/fs_clone/<node_name>/TXK_SYNC_create/fsclone_apply/wlsT2PApply/CLONE2017-06-22_16-27-46_1106077216.error shows:

java.lang.Exception: Unable to get free port for server oafm_server14 from port range 5001-5050

at oracle.as.clone.cloner.component.j2ee.util.J2EEGenericValidationUtil.getTemporaryPortFromPortRange(J2EEGenericValidationUtil.java:443)

at oracle.as.clone.cloner.component.j2ee.util.J2EEGenericValidationUtil.validateAndGetServerPort(J2EEGenericValidationUtil.java:322)

at oracle.as.clone.cloner.component.j2ee.util.J2EEGenericValidationUtil.validateServerConfig(J2EEGenericValidationUtil.java:171)

at oracle.as.clone.cloner.component.j2ee.config.GenericPasteConfigSteps.getServerConfig(GenericPasteConfigSteps.java:922)

at oracle.as.clone.cloner.component.j2ee.config.GenericPasteConfigSteps.executeGenericPasteConfig(GenericPasteConfigSteps.java:385)

at oracle.as.clone.cloner.component.J2EEComponentApplyCloner.doClone(J2EEComponentApplyCloner.java:259)

at oracle.as.clone.cloner.Cloner.doFinalClone(Cloner.java:63)

at oracle.as.clone.request.ApplyCloneRequest.applyArchive(ApplyCloneRequest.java:198)

at oracle.as.clone.request.ApplyCloneRequest._clone(ApplyCloneRequest.java:77)

at oracle.as.clone.process.CloningExecutionProcess.execute(CloningExecutionProcess.java:131)

at oracle.as.clone.process.CloningExecutionProcess.execute(CloningExecutionProcess.java:114)

at oracle.as.clone.client.CloningClient.executeT2PCommand(CloningClient.java:236)

at oracle.as.clone.client.CloningClient.main(CloningClient.java:124)

 

CHANGES:-

Both AD/TXK Delta 9+ are applied as per the Document: Oracle E-Business Suite Applications DBA and Technology Stack Release Notes for R12.AD.C.Delta.9 and R12.TXK.C.Delta.9 (Doc ID 2233485.1). This patch introduces context variable s_wls_t2p_temp_port_range which defaults to 5001-5050.

ROOT CAUSE:-

The context variable s_wls_t2p_temp_port_range which is too small a range if instance has moderate to large number of managed servers.

You can check the value of this setting:

SELECT extractValue(XMLType(TEXT),'//host[@oa_var="s_hostname"]') s_hostname,extractValue(XMLType(TEXT),'//WLST2PTEMP_PORT_RANGE') WLST2PTEMP_PORT_RANGE from fnd_oam_context_files where name not in ('TEMPLATE','METADATA') and (status is null or status !='H') and EXTRACTVALUE(XMLType(TEXT),'//file_edition_type') in ('patch') and CTX_TYPE = 'A' ORDER by s_hostname;

 

SOLUTION:-

Specify a larger range for s_wls_t2p_temp_port_range in apps tier context files and ensure autoconfig completes without issue.