EBS 12.2-- Output Post Processor(OPP) Performance in RTF and Excel reports.

The need to investigate the performance of OPP have arised by a long running Report in a Production EBS 12.2 instance. The name of report was Chart of Accounts - Segment Values Listing (XML)..
The issue was there for all the XML reports actually.. Especially, XML ereports which produce big sized RTF and Excel outputs..

In this blog post;

I will directly jump to the conclusino and then give the diagnostics & actions whic was taken to fix the issue. I m giving the conclusion first because; the conclusion is not differ according to the our actions, whatever the actions are...

Okay.. This is a limitation problem.
I mean, as OPP is a Java Concurrent Manager dedicated to BI Publisher, and as BI Publisher is all about java processing; and because Concurrent Tier uses 32 Bit JVM in EBS 12.2; we are under control of the limits in 32 Bit JVM ..

Altough, EBS 12.2 uses 10.1.3.4.2 version of BI Publisher,  it is still uses a 32 bit JVM in XML processing.
So, in such a large RTF processing/producing , there is nothing that can be done about the performance of OPP....

Note that:
These are the facts about the BIP output formats from an RTF layout template type:
- PDF output has the most efficient file size
- RTF output generates several times larger than pdf for the same xml data set size
- Excel output (which is really XHTML format) can be 10X larger than the pdf for the same xml data set size

What are the performance characteristics of 64-bit versus 32-bit VMs?

Generally, the benefits of being able to address larger amounts of memory come with a small performance loss in 64-bit VMs versus running the same application on a 32-bit VM. This is due to the fact that every native pointer in the system takes up 8 bytes instead of 4. The loading of this extra data has an impact on memory usage which translates to slightly slower execution depending on how many pointers get loaded during the execution of your Java program. The good news is that with AMD64 and EM64T platforms running in 64-bit mode, the Java VM gets some additional registers which it can use to generate more efficient native instruction sequences. These extra registers increase performance to the point where there is often no performance loss at all when comparing 32 to 64-bit execution speed.
The performance difference comparing an application running on a 64-bit platform versus a 32-bit platform on SPARC is on the order of 10-20% degradation when you move to a 64-bit VM. On AMD64 and EM64T platforms this difference ranges from 0-15% depending on the amount of pointer accessing your application performs

Anyways.. Lets explore what I have done;  when the issue was escalated to me..
Note that: the cause is :32 bit JVM limitations in here but still; I m giving these info to you, because it might help you diagnosing similar issues in EBS 12.2

I have done  the following diagnostics;

• Traced the process(the running thread inside of it) using strace;

            strace -p 8527 (the main process)
           Process 8527 attached - interrupt to quit
          [ Process PID=8527 runs in 32 bit mode. ]
          futex(0xf7743bd8, FUTEX_WAIT, 8530, NULL

         strace -p 8530 (the thead that main process was waiting)
        Process 8530 attached - interrupt to quit
       [ Process PID=8530 runs in 32 bit mode. ]
         futex(0xf7507644, FUTEX_WAIT_PRIVATE, 1, NULL

• Looking at the load of the server

There is no load on the server. Java HotSpot(TM) Server VM (build 23.25-b01, mixed mode)
[appldev@erpdev scripts]$ top
top - 17:55:21 up 21:27, 9 users, load average: 2.06, 1.49, 1.21
Tasks: 413 total, 2 running, 411 sleeping, 0 stopped, 0 zombie
Cpu(s): 14.6%us, 1.1%sy, 0.0%ni, 78.0%id, 6.1%wa, 0.0%hi, 0.1%si, 0.0%st
Mem: 12198304k total, 12032184k used, 166120k free, 39948k buffers
Swap: 16383992k total, 318672k used, 16065320k free, 6002308k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
8527 appldev 20 0 822m 193m 19m S 99.8 1.6 15:46.39 java


• Java version:
Java version is

/u01/apps/fs1/EBSapps/comn/util/jdk32/bin/java -version
java version "1.7.0_25"
Java(TM) SE Runtime Environment (build 1.7.0_25-b15)
Java HotSpot(TM) Server VM (build 23.25-b01, mixed mode)


• The java program itself:
Problematic process is :

/u01/apps/fs1/EBSapps/comn/util/jdk32/bin/java -Dxdo.xliff.source=EBS -DCLIENT_PROCESSID=3969 -Dhttp.proxyHost= -Dhttp.proxyPort= -Dhttp.nonProxyHosts= -Djava.awt.headless=true -server -Xmx384m -Djava.security.egd=file:///dev/urandom -Doracle.apps.fnd.common.Pool.leak.mode=stderr:off -verbose:gc -mx600m -Ddbcfile=/u01/apps/fs1/inst/apps/DEV_erpdev/appl/fnd/12.0.0/secure/DEV.dbc -Dcpid=11756 -Dconc_queue_id=6269 -Dqueue_appl_id=0 -Dlogfile=/u01/apps/fs_ne/inst/DEV_erpdev/logs/appl/conc/log/FNDOPP11756.txt -DLONG_RUNNING_JVM=true -DOVERRIDE_DBC=true -DFND_JDBC_BUFFER_MIN=1 -DFND_JDBC_BUFFER_MAX=2 oracle.apps.fnd.cp.gsf.GSMServiceController


• OS , hostname and the kernel info:
uname -a
Linux erpdev 2.6.32-431.3.1.el6.x86_64 #1 SMP Fri Dec 13 06:58:20 EST 2013 x86_64 x86_64 x86_64 GNU/Linux


• Concurrent processing analysis using CP Analzer:

            CP Analyzer and upload the output - Doc ID 1411723.1

• OPP manager log:

           OPP.log file was as follows; 
          The problematic thing was GLXRLSEG_XML
          It starts at 10:06 , still continuing at 11:40

          [12/12/14 10:06:11 AM] [11816:RT636361] XML Publisher post-processing action complete.
          [12/12/14 10:06:12 AM] [11816:RT636361] Completed post-processing actions for request 636361.
         [12/12/14 10:11:28 AM] [OPPServiceThread0] Post-processing request 636387.
        [12/12/14 10:11:28 AM] [11816:RT636387] Executing post-processing actions for request 636387.
        [12/12/14 10:11:28 AM] [11816:RT636387] Starting XML Publisher post-processing action.
      [12/12/14 10:11:28 AM] [11816:RT636387]
      Template code: GLXRLSEG_XML

• The running java code from thread dump:

        java.lang.Thread.State: RUNNABLE 
      at oracle.xdo.parser.v2.XSLExprValue.mergeOrderedList(XSLExprValue.java:551)

• Java threads stack Dump using jstack:

          The running runnable process:

Worker-3" daemon prio=10 tid=0x23a00c00 nid=0x41b7 in Object.wait() [0x21669000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at oracle.ias.cache.TaskQ.waitForWork(TaskQ.java:255)
- locked <0x3354ad50> (a oracle.ias.cache.TaskQ)
at oracle.ias.cache.TaskQ.getTask(TaskQ.java:138)
- locked <0x3354ad50> (a oracle.ias.cache.TaskQ)
at oracle.ias.cache.WorkerThread.run(ThreadPool.java:303)

"9786:RT639072" daemon prio=10 tid=0x24002c00 nid=0x3a28 runnable [0x216b9000]
java.lang.Thread.State: RUNNABLE
at oracle.xdo.parser.v2.XSLExprValue.mergeOrderedList(XSLExprValue.java:551)
at oracle.xdo.parser.v2.XPathAxis.getDescNodeList(XPathAxis.java:200)
at oracle.xdo.parser.v2.XPathStep.evaluate(XPathStep.java:405)
at oracle.xdo.parser.v2.PathExpr.evaluate(XSLNodeSetExpr.java:873)
at oracle.xdo.parser.v2.ComparisonExpr.evaluate(XSLExpr.java:1457)
at oracle.xdo.parser.v2.XSLExprBase.testBooleanExpr(XSLExprBase.java:298)
at oracle.xdo.parser.v2.AndExpr.evaluate(XSLExpr.java:441)
at oracle.xdo.parser.v2.XSLExprBase.testBooleanExpr(XSLExprBase.java:298)
at oracle.xdo.parser.v2.XPathFunctionCall.evaluate(XPathFunctionCall.java:695)

• Os thead analysis:

OS Thread analysis: ps -eLo pid,ppid,tid,pcpu,comm | grep 19686

19686 17301 19686 0.0 java
19686 17301 19687 0.0 java
19686 17301 19688 0.0 java
19686 17301 19689 0.0 java
19686 17301 19690 0.0 java
19686 17301 19691 0.0 java
19686 17301 19692 0.0 java
19686 17301 19693 0.0 java
19686 17301 19694 0.0 java
19686 17301 19695 0.0 java
19686 17301 19696 0.0 java
19686 17301 19697 0.0 java
19686 17301 19698 0.0 java
19686 17301 19699 0.0 java
19686 17301 19700 0.0 java
19686 17301 19701 0.0 java
19686 17301 19703 0.0 java
19686 17301 19718 0.0 java
19686 17301 19719 0.0 java
19686 17301 19720 0.0 java
19686 17301 19721 0.0 java
19686 17301 19722 0.0 java
19686 17301 19723 0.0 java
19686 17301 19724 0.0 java
19686 17301 19725 0.0 java
19686 17301 19726 0.0 java
19686 17301 19727 0.0 java
19686 17301 19728 0.0 java
19686 17301 19729 0.0 java
19686 17301 19730 0.0 java
19686 17301 19733 0.0 java
19686 17301 19734 0.0 java
19686 17301 20212 99.4 java The only thread that does the work is this.
19686 17301 20302 0.0 java

Okay, after collecting the diagnostics info, I have taken following actions to tune OPP, and I acutally tuned the OPP process but these did not fix the problem.

1)
In XML Publisher Administrator responsibility >Administration > Configuration
- under : Properties -> General -> set a temporary directory
This directory should be at least 5 times larger than the largest anticipated data file.
Support recommends the directory to be at least 5GB.

2)
XML Publisher Administrator responsibility ->
Navigation Path : XML Publisher Administrator responsibility
- query the data definition
- on the View Data Definition page select Edit Configuration button
- set 'Use XML Publisher's XSLT processor' to True
- set 'Enable scalable feature of XSLT processor' to True
- set 'Enable XSLT runtime optimization' to True
Note that these property values, when set at the Data Definition level, takes precedence over values set at the Site level.

3)
in System Administrator  > System
- set Concurrent:OPP Process Timeout = 43200
- set Concurrent:OPP Response Timeout = 43200
(these values are for 12 hours in seconds)

4)

update FND_CP_SERVICES
set DEVELOPER_PARAMETERS = 'J:oracle.apps.fnd.cp.gsf.GSMServiceController:-mx2048m'
where SERVICE_ID = (select MANAGER_TYPE from FND_CONCURRENT_QUEUES
where CONCURRENT_QUEUE_NAME = 'FNDCPOPP');

5)

rebooted the server (for futex wait)

6)

Changed the java process to use urandom instead of random

7)

Stopped the NTP

/etc/init.d/ntp stop
then;
date `date +"%m%d%H%M%C%y.%S"`

8)

Changed OPP thead counts, made it to run single thead; then made it to run in several thread.. It was just like a Guessing Game

The actions above could at least made the report to successfully complete in 1 hours..To decrease this completion time; one should use BI Publisher Enterprise 11g product is 64-bit as it will use the 64-bit JVM which is exponentially larger.

By the way, I said using BIP 64 is a solution, but BIP 64 bit is a separate application/rquired to be installed separatley. BIP 64 bit  can not be embedded into EBS, as it is not 32 bit..
BI Publisher 32 bit however,can be embedded into EBS.. It comes embedded in EBS. Oracle used the libraries from it to EMBED it into EBS, to replace/upgrade the aging 5.6.3 version.
They were able to do this because 10.1.4.3.2 is still 32-bit.