Output Post Processor (OPP) Hangs With High CPU Utilization in R12

Issue:

OPP (java) processes consuming High CPU.Most of the time it is due to un-optimized "Template Code" that causes slowness.
It could be either Standard Template Code or Custom Code.

Error in concurrent program log:

Post-processing of request 657502 failed at 10-FEB-2016 21:20:40 with the error message:
The concurrent manager has timed out waiting for the Output Post-processor to finish this request.

Check that there are enough Output Post-processor service processes running.

Cause:

Inactive OPP (java) processes consuming High CPU(100% cpu) or Might be Java garbage collector gets OPP java process hung.

Solution:

We need to collect all the required details to identify the report (Template Code) that caused the issue. Once you identify the "Template Code", you need to take the corrective action to fix it. 

Below are the steps:

1. Identify <PID> of OPP that is spinning. Use top (or) prstat

   1.1 top

   1.2 ps -ef|grep <high cpu pid>

2. Generate the java thread dump. It will generate trace in opp log.

  2.1 $kill -3

  Ex: Kill -3 5456

  2.2 Identify opp file using below command

  Ex: ps -ef|grep <high cpu pid>

[applmgr@testdb ~]$ ps -ef|grep 5456
applmgr   5456 7037  0 Oct18 ?        00:55:15 /u01/oracle/APPS/apps/tech_st/10.1.3/appsutil/jdk/bin/java -DCLIENT_PROCESSID=7133 -server -Xmx384m -XX:NewRatio=2 -XX:+UseSerialGC -Doracle.apps.fnd.common.Pool.leak.mode=stderr:off -verbose:gc -mx512m -Ddbcfile=/u01/oracle/APPS/inst/apps/testserver/appl/fnd/12.0.0/secure/testdb.dbc -Dcpid=2044321 -Dconc_queue_id=2158 -Dqueue_appl_id=0 -Dlogfile=/u01/oracle/APPS/inst/apps/testserver/logs/appl/conc/log/FNDOPP2044321.txt -DLONG_RUNNING_JVM=true -DOVERRIDE_DBC=true -DFND_JDBC_BUFFER_MIN=1 -DFND_JDBC_BUFFER_MAX=2 oracle.apps.fnd.cp.gsf.GSMServiceController
applmgr  24740 24696  0 08:37 pts/1    00:00:00 grep 5456

  2.3 Trace log generte like below

  Full thread dump Java HotSpot(TM) Server VM (20.71-b01 mixed mode):

"Worker-4" daemon prio=3 tid=0x00156400 nid=0x3091 in Object.wait() [0x74e7f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at oracle.ias.cache.TaskQ.waitForWork(Unknown Source)
- locked <0xa2938800> (a oracle.ias.cache.TaskQ)
at oracle.ias.cache.TaskQ.getTask(Unknown Source)
- locked <0xa2938800> (a oracle.ias.cache.TaskQ)
at oracle.ias.cache.WorkerThread.run(Unknown Source)


"GSMServiceController:657502" prio=3 tid=0x0077e400 nid=0x38 runnable [0x7467f000]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at oracle.net.ns.Packet.receive(Packet.java:282)
at oracle.net.ns.DataPacket.receive(DataPacket.java:103)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:230)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:175)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:100)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:85)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:122)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:78)
at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1179)
at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1155)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:279)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:186)
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:521)
at oracle.jdbc.driver.T4CCallableStatement.doOall8(T4CCallableStatement.java:202)
at oracle.jdbc.driver.T4CCallableStatement.executeForRows(T4CCallableStatement.java:1005)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1307)
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3449)
at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3550)
- locked <0xa2938140> (a oracle.jdbc.driver.T4CConnection)
at oracle.jdbc.driver.OracleCallableStatement.execute(OracleCallableStatement.java:4710)
- locked <0xa2938140> (a oracle.jdbc.driver.T4CConnection)
at oracle.jdbc.driver.OraclePreparedStatementWrapper.execute(OraclePreparedStatementWrapper.java:1374)
at oracle.apps.fnd.cp.gsm.GenCartComm.getQueueMessage(GenCartComm.java:189)
at oracle.apps.fnd.cp.gsf.GSMStateMonitor.waitForNextEvent(GSMStateMonitor.java:98)
at oracle.apps.fnd.cp.gsf.GSMServiceController.mainLoop(GSMServiceController.java:236)
at oracle.apps.fnd.cp.gsf.BaseServiceController.run(BaseServiceController.java:71)
at java.lang.Thread.run(Thread.java:680)

3. Get “thread ID” which consumes High CPU. Use this command.

  3.1 $ ps -eLo pid,ppid,tid,pcpu,comm | grep <PID>

Solaris
$ prstat -L -p 5456 1 1
If you do not have prstat available on your Solaris installation, you can do the following instead:
ps -Le -o pid,user,s,lwp,pcpu,args | awk '$3 != "S" { print }'

Linux (discussed in this document)
$ ps -eLo pid,ppid,tid,pcpu,comm | grep <PID>

AIX.
ps -mp 5456 -o THREAD will show the following:

HP-UX
Click hp_prstat to download the hp_prstat utility developed by WebLogic Support.

Windows
Run pslist -d <Java PID>


4. Convert the “thread ID” to Hexadecimal which helps to identify the “Template code” (potential cause).

"GSMServiceController:657502" prio=3 tid=0x0077e400 nid=0x38 runnable [0x7467f000]
   java.lang.Thread.State: RUNNABLE

5. Resolution - Optimizing the Template code.

From the above output take out the string 657502 which is the Concurrent Request ID. 
You can now search for 657502 in OPP log again. 
You should be able to locate the template code.

Reference: 2028617.1

How to License A New Product/Module in Oracle Applications

How to License A New Product/Module in Oracle Applications

Below are the steps for license product.

1. log in Oracle Application Manager (OAM) and select Site Map -> Administration tab -> License Manager

2. Click Products -> License Applications Product 

   select 'Approvals Management(our scenario)' -> click Next and Submit.

3. Now load forms/database objects to database for that product using adadmin

            AD Administration Main Menu
   --------------------------------------------------

   1.    Generate Applications Files menu

   2.    Maintain Applications Files menu

   3.    Compile/Reload Applications Database Entities menu

   4.    Maintain Applications Database Entities menu

   5.    Change Maintenance Mode

   6.    Exit AD Administration
   
Select Generate Application Files menu

Enter your choice [6] : 1

         Generate Applications Files
   ----------------------------------------

   1.    Generate message files

   2.    Generate form files

   3.    Generate report files

   4.    Generate product JAR files

   5.    Return to Main Menu

Run all "Generate Applications Files" for licensed product/module.

Back to Main Menu

Select Compile/Reload Applications Database Entities menu

Enter your choice [6] : 3

        Compile/Reload Applications Database Entities
   ---------------------------------------------------

   1.    Compile APPS schema

   2.    Compile menu information

   3.    Compile flexfields

   4.    Reload JAR files to database

   5.    Return to Main Menu

run all of the following Menu options:

Compile APPS schema
Compile menu information
Compile flexfields

4. Run autoconfig

5. Verify Product installed successfully or not using below query.

select fa.APPLICATION_SHORT_NAME, fpi.PATCH_LEVEL, DECODE(fpi.STATUS, 'I','Installed',
'S','Shared', 'N', 'Inactive', fpi.STATUS) Status , fpi.DB_STATUS
from fnd_product_installations fpi,FND_APPLICATION fa
where fpi.APPLICATION_ID in (
select APPLICATION_ID from FND_APPLICATION where APPLICATION_SHORT_NAME like 'AME')
and fa.APPLICATION_ID=fpi.APPLICATION_ID; 

You have encountered an unexpected error. Please contact the System Administrator for assistance with error oracle.apps.fnd.framework.OAException: Application: FND, Message Name: FND_NO_DATABASE_CONNECTION

ISSUE:

You have encountered an unexpected error. Please contact the System Administrator for assistance.

Exception details:
oracle.apps.fnd.framework.OAException: Application: FND, Message Name: FND_NO_DATABASE_CONNECTION.

error log in oacore log file:

oracle.apps.fnd.framework.OAException: Application: FND, Message Name: FND_NO_DATABASE_CONNECTION.
        at oracle.apps.fnd.framework.server.OANullDBTransactionImpl.noDatabaseConnection(OANullDBTransactionImpl.java:653)
        at oracle.apps.fnd.framework.server.OANullDBTransactionImpl.isLoggingEnabled(OANullDBTransactionImpl.java:930)
        at oracle.apps.fnd.framework.OASessionCookieHelper.timeoutApplicationModule(OASessionCookieHelper.java:260)
        at oracle.apps.fnd.framework.webui.OAHttpSessionCookieImpl.timeout(OAHttpSessionCookieImpl.java:632)
        at oracle.jbo.http.HttpSessionCookieImpl.timeout(HttpSessionCookieImpl.java:160)
        at oracle.jbo.http.HttpContainer.fireTimeout(HttpContainer.java:513)
        at oracle.jbo.http.HttpContainer.timeout(HttpContainer.java:240)
        at oracle.jbo.http.HttpContainer.valueUnbound(HttpContainer.java:299)
        at com.evermind.server.http.EvermindHttpSession.destroy(EvermindHttpSession.java:472)
        at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:1007)
        at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:978)
        at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:411)
        at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:378)
        at com.evermind.server.http.SessionAsyncInvalidateHandler.invalidateSession(SessionAsyncInvalidateHandler.java:159)
        at com.evermind.server.http.SessionAsyncInvalidateHandler.run(SessionAsyncInvalidateHandler.java:119)
        at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
        at java.lang.Thread.run(Thread.java:619)

CAUSE:

AM Pool created during REST request does not contain the connect string information. When a new AM is requested as part of normal AM checkout, it errors out with FND_NO_DATABASE_CONNECTION.

Resolution: Include connect string information while creating AM Pool for REST invocation.

SOLUTION:

Work around

Restart the applications

cd $ADMIN_SCRIPTS_HOME
sh adstpall.sh

Wait for all processes clear.

sh adstrtal.sh and Test again.

Permanent fix:

For permanent fix apply the below patch.

12.1.2 and 12.1.1 Customers apply and test Patch: 9908921

Release 12.1.3 Customers apply and test Patch: 11832737

Reference: 1298103.1