Parallel Page Engine (PPE) parameters for enabling tracing and debugging

Here are the most relevant parameters for enabling tracing and debugging of the 
Parallel Page Engine (PPE) in Oracle Portal:

   <init-param>
   <param-name>logmode</param-name> 
   <param-value>request</param-value>
   </init-param>
   
      LOGFILE:
         $ORACLE_HOME/j2ee/OC4J_Portal/application-deployments/portal/ 
      
      Allowed values are:
         none - No debug messages
         perf - Performance messages only
         debug - General debug messages
         request - Details of requests made by the PPE
         content - Details of the content of requests made by the PPE
         parsing - Details of metadata parsing
         all - All debug messages 
   
   <init-param>
   <param-name>showPageDebug</param-name>
   <param-value>true</param-value>
   </init-param>
   
      If you set showPageDebug to true, the Page timing information is shown on 
      every request. I don't recommend doing this instead you can pass debug
      parameter to any Portal page like so:
      
         ?_debug=3
   
   
   <init-param>
   <param-name>urlDebugMode</param-name>
   <param-value>5</param-value>
   </init-param>
   
      Specifies the highest value of the _debug URL parameter that the PPE should 
      honor. Possible values for _debug are:
      
      none, 0, 1, 2, 3, 4, and 5
      
      If a value higher than that allowed is received by the PPE, it is reduced 
      to the highest value permitted, or ignored if no value is allowed.
      
      The values build incrementally. For example, at debug value 2, values for 
      debug level 1 and 0 are also recorded. 


Here's more information on Timing and Caching Statistics

   All OracleAS Portal pages can be run in a special mode in which timing and 
   caching information is displayed. If you want to see this debug information 
   on every page you can set the Parallel Page Engine Parameter showPageDebug 
   to true in the web.xml file.
   
   See Also:
   Appendix D, Configuring the Parallel Page Engine
   
   If you want to see the debug information for just a few select pages and 
   portlets, you can control the logging level by the _debug URL parameter. 
   For example, to see the timing statistics for the following OracleAS Portal 
   page:
   
      http://abc.com/servlet/page?_pageid=21
   
   You can manually insert &_debug=3
   
   To make:
   
      http://abc.com/servlet/page?_pageid=21&_debug=3
   
   Possible values for _debug are 0, 1, 2, 3, 4, and 5.
   
   Values greater than 1 will potentially raise the logmode value for the 
   duration of the request, and trigger all request log messages to be echoed 
   into the page response. 

Now go ahead setup logmode and urlDebugMode as follows:

   <init-param>
   <param-name>logmode</param-name> 
   <param-value>request</param-value>
   </init-param>

   <init-param>
   <param-name>urlDebugMode</param-name>
   <param-value>5</param-value>
   </init-param>

In the following file:

   $ORACLE_HOME/j2ee/OC4J_Portal/applications/portal/portal/WEB-INF/web.xml

You can use the following chars to comment out blocks of parameters:

    <!--
    -->


Bounce services using:

   omnctl shutdown
   opmnctl startall

The logmode request information will be written into application.log:

   host.portal-> ls -l $ORACLE_HOME/j2ee/OC4J_Portal/application-deployments/portal/
   total 12
   drwxrwx---   2 oracle   dba          512 May  8  2007 OC4J_Portal_default_island_1
   -rw-r--r--   1 oracle   dba          563 Oct  3 14:48 jazn-data.xml
   -rw-rw----   1 oracle   dba          563 Oct  3 14:48 jazn-data.xml.smibak
   -rw-rw----   1 oracle   dba          955 May  8  2007 orion-application.xml
   drwxrwx---   3 oracle   dba          512 Dec  6 14:22 portal
   -rw-rw----   1 oracle   dba          215 May  8  2007 principals.xml
   host.portal->

this is where it is actually:

   host.portal-> ls -l $ORACLE_HOME/j2ee/OC4J_Portal/application-deployments/portal/OC4J_Portal_default_island_1
   total 5712
   -rw-rw----   1 oracle   dba      2909817 Dec  6 14:26 application.log
   host.portal->

You can now do a "tail -f application.log" and watch the PPE output it's work.

The other thing that you will be able to do now is to run a DEBUG MODE on any page:

DEBUG MODE:
   http://portal.domain.com/portal/page/portal/CustomApp/page_name?_debug=3

Here are some other helpfull modes that you can specify when calling a page:

EDIT MODE:
   http://portal.domain.com/portal/page/portal/CustomApp/page_name?_mode=16

DIRECT LINK TO page's component (page_name_column_one):
   http://portal.domain.com/portal/page/portal/CustomApp/page_name/page_name_column_one?_debug=3

After I ran these and watched the output of debug mode I came to a conclusion 
that the problematic component is - page_name_column_one

But the most interesting thing is that the load times, while not that great,
are actually not horrible either what's really bad are these:

   Information for Page 912319536/338480
   Elapsed Time: 12949 msecs
   Page meta data generation time: 642 msecs (wait = 0)
   Page meta data Cache Status: Web Cache:- MISS,NON-CACHEABLE [N], Cache 
   Expires: null seconds, Age in Cache: null seconds., File System Cache:-null
   Login meta data generation time: 12299 msecs (wait = 1)
   Login meta data Cache Status: Web Cache:- HIT [H], Cache Expires: 2040 
   seconds, Age in Cache: 13 seconds. 
   
   Information for Page /CustomApp/page_name/page_name_column_one
   Elapsed Time: 18011 msecs
   Page meta data generation time: 518 msecs (wait = 1)
   Page meta data Cache Status: Web Cache:- MISS,NON-CACHEABLE [N], Cache 
   Expires: null seconds, Age in Cache: null seconds., File System Cache:- null 
   Login meta data generation time: 17475 msecs (wait = 1) 
   Login meta data Cache Status: Web Cache:- MISS,NEW [M], Cache Expires: 2040 
   seconds, Age in Cache: 17 seconds., File System Cache:- null 

Notice that the "Login meta data generation time" is well into tens of 
thousands of milliseconds (10-17 seconds!).  These horrible timings were 
noticed whenever a new browser session was started - on all subsequent page
loads the "Login meta data generation time" was being pulled from WebCache.

The solution to "Login meta data generation time" is to set Portlet provider to "Public":

Navigate to Portal Navigator -> Providers -> Registered Providers ->
   click on the "Edit Registration" link for the provider name that you want to modify ->
   click on the "Connection" tab -> 
   Under "User/Session Information" section make sure it's set to "Public"
   
Here's the link to Portal Navigator:
   http://portal.domain.com/portal/page/portal/TOPLEVELSITE/Navigator/SiteExplorer

If you cannot set all your providers to "Public" then you need to tune/reduce 
"Login meta data generation time":

   When a provider uses the session, then the Portal database tries to call 
   the initSession call of the provider, while generating the Login Meta Data 
   (LMD).  The call is made via HTTP to the URL for the Web provider that you 
   specify in the General Properties (Edit Registration page) - for example:

      http://portal-host.domain.com:7777/PROVIDER_NAME/providers/struts/
   
   My guess is that you'll need to tune the call to provider.initSession:

      OracleAS PDK for Java 10.1.2.0.2

   Configuring the Parallel Page Engine