Friday, February 1, 2013

How to Diagnose: 11i Basic Apache/mod_jserv Troubleshooting with Hello.class

How to Diagnose: 11i Basic Apache/mod_jserv Troubleshooting with Hello.class


How to Diagnose: 11i Basic Apache/mod_jserv Troubleshooting with Hello.class [ID 230688.1]
The Hello Test
Shutdown the apache web server.
1.       Delete or rename the existing logfiles.
a.       from ".../iAS/Apache/Apache/logs" delete everything in this directory
b.       from ".../iAS/Apache/Jserv/logs" delete everything in this directory, including the underlying   jvm directory
2.       Edit the file .../iAS/Apache/Apache/conf/httpd.conf to enable debug for apache.
  set the LogLevel to debug  à ErrorLog /space/v1154/visora/iAS/Apache/Apache/logs/error_log and access_log
. The access_log gives the main hint of what the user was requesting at a given time.  The error_log hints at what happened to that request, which might just be that it was forwarded to an underlying module.  The underlying module log gives further specifics on how the request was handled.
3.       Edit the .../iAS/Apache/Jserv/etc/jserv.conf to enable debug for the JServ module.
Set the ApJServLogLevel to debug àApJServLogFile /space/v1154/visora/iAS/Apache/Jserv/logs/mod_jserv.log
4.       Edit the file .../iAS/Apache/Jserv/etc/jserv.properties to enable debug for the JVM.
set log=true, log.timestamp=true àlog.file=/space/v1154/visora/iAS/Apache/Jserv/logs/jserv.log

user click on any Self Service Request or any program which uses Java, then Apache forwards this request to mod_jserv
error : java.lang.OutOfMemoryError or java.lang.NoClassDefFoundError

5.       Start the apache server.
6.  Pause for a minute
7.  Do the test and capture it in the logfiles
 Immediately goto a browser window and access the Hello test by using a URL similar to the following:

      http://myserver.us.oracle.com:8005/servlets/Hello

In this case "myserver" is the name of my server on the "us.oracle.com" domain and my apache web server is listening on port 8005. In my typical case, the file "Hello.class" is located in the virtual directory named
servlets which is typically .../iAS/Apache/Jserv/servlets in the actual filesystem.
      9.  Run the other tests
              You may have also been asked to do other tests by Oracle Support, such as to attempt to login or                                                                                                                         navigate along a specific sequence of steps to recreate the problem that is the subject of your TAR.  Do this test here at this stage.
10.  Immediately shutdown the apache server as in step 1.
Once you've recreated the problem and captured the details within the logs, it is generally expected that you will immediately stop the apache server.  Letting Apache continue to run in this verbose state just puts more and more lines between the relevant test data and the end of the file.

11. Gather all of the log and configuration files together at once.
Gather up all of the following logfiles and configuration files for analysis (approximately 80 files).  See the zip command, below (highlighted):
.../iAS/Apache/Apache/logs/* (perhaps 10 files)
.../iAS/Apache/Apache/conf/* (typically 30 files)
.../iAS/Apache/Jserv/logs/*     (typically 2 files)
.../iAS/Apache/Jserv/logs/jvm/* (6 files for 11.5.8 and later)
.../iAS/Apache/Jserv/etc/* (typically 24 files)
autoconfig context file
/etc/hosts file
the DBC files

Determining the JDK Version Used by Apache

$IAS_CONFIG_HOME/Apache/Apache/bin/java.sh` -version;"

Analysis Examples - Initial Quick Checks

1. The logfile.zip filename
2. What version of apache is this?
It is rarely necessary to ask for "httpd -v" as a separate step, simply look for the word "built" in the apache error_log where the LogLevel was at least Info:
[Fri Apr 4 16:58:42 2008] [notice] Oracle HTTP Server Powered by Apache/1.3.19 configured -- resuming normal operations
[Fri Apr 4 16:58:42 2008] [info] Server built: Jul 13 2005 23:20:35 (iAS 1.0.2.2.2 rollup 5)

Analysis Fundamentals
1.  The apache web server depends on numerous underlying modules to get things done.  Therefore, an individual error in an individual log file has little meaning.  Any problem of significance will have to be viewed from the perspective of several different logs to be diagnosed properly.  The different perspectives can generally be aligned by the timestamps.
2. Avoid the temptation to chase every little error seen.  The method of gathering logs described in this paper keeps the logfiles concise, but there still will be a great deal of tangential information surrounding the important thread that should be the focus.  These tangents are reduced by starting apache, doing the test and only the test, and then stopping apache. 
. The access_log gives the main hint of what the user was requesting at a given time.  The error_log hints at what happened to that request, which might just be that it was forwarded to an underlying module.  The underlying module log gives further specifics on how the request was handled.
Example 1 - UNIX instance, Problem: AppsLogin simply returns "Done" and no login screen appears
Not to spoil the ending, but in this example I've started the middle tier but left the database tier DOWN.  The purpose of the example is to illustrate the highlights of how an analysis of the logfile.zip can be done.  This example will only last one page, so apologies in advance at the sparse level of detail on the inner workings of iAS1.0.2.2.2.   This is a simple, illustrative example.
access_log - quick walk through

Since this test was just the "Hello Test" and an attempt to Login, the entire access_log is direct and to the point:

access_log:
myserver.us.oracle.com - - [04/Apr/2008:16:58:42 -0700] "GET /oprocmgr-service?cmd=Register&index=0&modName=JServ&grpName=FormsGroup&port=18050 HTTP/1.1" 200 15

myserver.us.oracle.com - - [04/Apr/2008:16:58:43 -0700] "GET /oprocmgr-service?cmd=
Register&index=0&modName=JServ&grpName=XmlSvcsGrp&port=19050 HTTP/1.1" 200 15

myserver.us.oracle.com - - [04/Apr/2008:16:58:43 -0700] "GET /oprocmgr-service?cmd=Register&index=0&modName=JServ&grpName=DiscoGroup&port=17050 HTTP/1.1" 200 15

myserver.us.oracle.com - - [04/Apr/2008:16:58:43 -0700] "GET /oprocmgr-service?cmd=Register&index=0&modName=JServ&grpName=OACoreGroup&port=16050 HTTP/1.1" 200 15
These first four entries indicate normal JVM startup. As can be confirmed in the jserv.conf, the four typical JServ's are the FormsGroup, XmlSvcsGrp, DiscoGroup, and OACoreGroup with ONE JVM assigned to each. These entries indicate successful (HTTP status code 200) registration of the JVMs with the oprocmgr.

access_log (continued):
10.148.54.240 - - [04/Apr/2008:16:59:49 -0700] "GET /servlets/Hello HTTP/1.1" 200 208
Next, we have the attempt to access the "Hello" class. This also reported a "200" with 208 bytes sent and is the successful result shown in the screenshot at the beginning of this note. This indicates that the JVMs, in general, are working. Simply put, the request for "Hello" goes to the apache server, the underlying mod_jserv module, specifically the OACoreGroup JVM, which runs the "Hello.class" program and sends the result back up the stack.  At this point we have some assurance that the oprocmgr and the JVM's in general are not the reason users cannot login.
access_log (continued):
10.148.54.240 - - [04/Apr/2008:16:59:49 -0700] "GET /favicon.ico HTTP/1.1" 404 217
This next line (above) can be ignored. The test is to test the "Hello" and an attempt to login. Do NOT get distracted by miscellaneous error messages that have nothing to do with "Hello" nor "AppsLogin" (or whatever the focus of the test is).  The focus of this "TAR" is to determine why the login page doesn't appear.

access_log (continued):
10.148.54.240 - - [04/Apr/2008:17:00:02 -0700] "GET /servlets/AppsLogin HTTP/1.1" 200 5
10.148.54.240 - - [04/Apr/2008:17:01:03 -0700] "GET /servlets/AppsLogin HTTP/1.1" 200 5
Finally, we have two attempts to get AppsLogin. While both return a favorable "200-OK", only 5 bytes were returned and none of the expected followup activity is seen. This illustrates why a single logfile by itself tells only a small part of the story. To get the rest of the story, take these timestamps into the other logs.


error_log
Again, don't get lost picking at each little odd thing. Align the timestamps and look for cause and effect:

error_log: Timestamp for the Hello test:
[Fri Apr 4 16:59:49 2008] [debug] opm_tbl.c(1613): OPM:selected proc is:mod=JServ,grp=OACoreGroup,host=myserver.us.oracle.com,bindadd=myserver.us.oracle.com,port=16050,prot=0
The Oracle Procedure Manager chose the OACoreGroup JVM for the Hello test. This means that further information can be found in the Jserv.log.

error_log: Timestamp for the favicon.ico error which we are ignoring:
[Fri Apr 4 16:59:49 2008] [error] [client 10.148.54.240] File does not exist: /space/v115cu2/visccomn/portal/VISC_myserver/favicon.ico
Requesting a favorites icon is something modern browsers do automatically.  Not all websites, including 11i e-Business suites, necessarily have a favorites icon setup.  This has nothing to do with the AppsLogin screen, so let us move on.
error_log: Timestamps for the two AppsLogin attempts:
[Fri Apr 4 17:00:02 2008] [debug] opm_tbl.c(1613): OPM:selected proc is:mod=JServ,grp=OACoreGroup,host=myserver.us.oracle.com,bindadd=myserver8.us.oracle.com,port=16050,prot=0
...
[Fri Apr 4 17:01:03 2008] [debug] opm_tbl.c(1613): OPM:selected proc is:mod=JServ,grp=OACoreGroup,host=myserver.us.oracle.com,bindadd=myserver.us.oracle.com,port=16050,prot=0
Similar to the Hello test, the above two lines match the two "GET AppsLogin" and indicate that the request was cleanly passed to the mod_jserv.  Furthermore, the JVM chosen was the OACoreGroup so further information is available in the file jserv.log which we enabled earlier (contrast this with the FormsGroup JVM, for example, that calls its log the "forms.log").  Since we found that the Hello test worked via the OACoreGroup JVM, there must be something wrong with the JVM that the simple Hello test doesn't need, but that AppsLogin does (like maybe database connectivity).


jserv.log

Meanwhile, in the jserv.log (watch the timestamps):

The Hello test was initialized:
[04/04/2008 16:59:49:387 MST] <servletLog> Hello: init
The AppsLogin was initialized too:
[04/04/2008 17:00:02:399 MST] <servletLog> AppsLogin/oracle.apps.fnd.sso.AppsLogin: init
But the log ends abruptly here. The AppsLogin can't go anywhere because it needs to talk to the database and the database is down. How do we know? By looking back to the timestamp of where the Jservs were initializing, especially the OACoreGroup.

Putting it all together:

access_log:
myserver.us.oracle.com - - [04/Apr/2008:16:58:43 -0700] "GET /oprocmgr-service?cmd=Register&index=0&modName=JServ&grpName=OACoreGroup&port=16050 HTTP/1.1" 200 15

error_log:
[Fri Apr 4 16:58:43 2008] [debug] opm_tbl.c(1029): OPM:Into opm_tbl_update_proc, mod=JServ,grp=OACoreGroup,host=dcollierpc8.us.oracle.com,index=0,port=16050,stat=2
[Fri Apr 4 16:58:43 2008] [debug] opm_tbl.c(2527): OPM:Into opm_tbl_update_bcnode, host=dcollierpc8.us.oracle.com,port=-1

jserv.log
(abbreviated stack dumps; many things failing)
[04/04/2008 16:58:45:272 MST] <servletLog>
Exception in static block of jtf.cache.appsimpl.AppsCacheLogger. Stack trace is: oracle.apps.fnd.common.AppsException: oracle.apps.fnd.common.PoolException: Exception creating new Poolable object.
...
Caused by: oracle.apps.fnd.common.PoolException: Exception creating new Poolable object.
... 51 more
Caused by: oracle.apps.fnd.common.AppsException: oracle.apps.fnd.common.AppsException: java.sql.SQLException: ORA-01034: ORACLE not available
ORA-27101: shared memory realm does not exist
....
[04/04/2008 16:58:46:045 MST] <servletLog> Could not initialize Oracle Apps. Please check the system log file!
In this example, the access_log and error_log only added context to the underlying error in the jserv.log that turned out to be the crux of the issue.  This is not always the case.

  


Check for debug log files:
3. Enable debug logging for Apache
AutoConfig variable
                    s_apache_loglevel   Change to "debug"    Default value is "warn"

Manual update
                    Modify $IAS_ORACLE_HOME/Apache/Apache/conf/httpd.conf
                                         LogLevel debug


4. Enable debug logging for mod_jserv
AutoConfig variable
                    s_apjservloglevel   Change to "debug"    Default value is "warn"

Manual update
                    Modify $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.conf
                                         ApJServLogLevel debug


5. Enable debug logging for Jserv
AutoConfig variable
                    s_oacorelog   Change to "true"    Default value is "false"

Manual update
                    Modify $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties
                                         log=true
                                         log.channel=true
                                         log.channel.info=true
                                         log.channel.debug=true


6. Enable debug logging for Forms Listener Servlet JVM (Optional)

This step is only relevant if you have implemented Forms Listener Servlet as
described in Note 201340.1 "Using Forms Listener Servlet with Oracle Applications 11i"
and the reported problem is to do with the Core Forms

AutoConfig variable
                    s_oaformslog   Change to "true"    Default value is "false"

Manual update
                    Modify $IAS_ORACLE_HOME/Apache/Jserv/etc/forms.properties
                                         log=true
                                         log.channel=true
                                         log.channel.info=true
                                         log.channel.debug=true





When Client makes a request in browser for Oracle Application using URL like http // servername : port number , where servername is your webserver name & port number is port on which your webserver is listening . If no port is given & using http that means webserver is listening on port 80 ( 443 for https ) . I am currently not taking proxy server or loadbalancer into account for this post .

Oracle-Apache is nothing but Oracle has added some component (mod_plsql, mod_jserv, mod_osso) in to Apache Webserver & realeased it as Oracle-Apache Server.
File System & important file
Where it exists on File System : As you know there are three ORACLE_HOME in Apps so WebServer is under IAS_ORACLE_HOME ( iAS stands for internet Application server ) under INSTALL_BASE/ora9/iAS directory.
Importanf files/dir in iAS Directory : As Apps DBA following files/dir are important to us SID_Hostname.env, Apache, network . Env file is to set environment variable to iAS_ORACLE_HOME (During iAS patching )
Apache is main directory where your most webserver configuration Sit also called as APACHE_TOP . Imp. files/dir under this directory is Apache, Jserv and plsql .
As you know Apache is build on modules Apache directory contains config & executable files for main Apache Module, mod_jserv related stuff goes in Jserv directory, mod_plsql related under plsql .
mod_jserv caters Jserv requestes like Self Service, Servlets, jsp pages
mod_plsql caters plssql requests like anything after /pls ( executing packages & procedures in DB)

Though there are lot of important file but I am naming those which come across in Apps DBA life quite often
Under iAS/Apache/Apache important directory/files is
bin (executable, apachectl,httpd) , conf ( httpd.conf, httpd_pls.conf, oracle_apache.conf ),
logs ( access_log, access_log_pls, error_log, error_log_pls, httpd.pid )
Under iAS/Apache/Jserv files you want to know are
etc (config files), logs( jvm, mod_jserv.log)
Under iAS/Apache/modplsql its
cache (cookie , plsql) , cfg (wdbsvr.app , *.conf)
Its not feasible to explain features/importance of all files here so I will explain these in details sometime later. Later check how WebServer Starts in Oracle Apps or Oracle Application Server .


Startup Sequence
In Oracle apps as DBA you start your services from OAD_TOP or COMMON_TOP / admin /scripts /CONTEXT_NAME ( SID_HOSTNAME ) (This location might differ depending on you apps version this is for 11.5.8 or Higher) , you use adstrtall.sh script which in turn calls ServiceControl ( In current Version ) earlier used to call adapcctl.sh in same directory( where ad application's DBA apc Apache ctl control ) . So adapcctl.sh is used to start stop oarcle application WebServer . This script calls shell script apachectl ( in IAS_ORACLE_HOME/Apache/Apache/bin , This is text file & you can open and read it ) which in turn calls httpd (executable for http daemon ) .

Configuration files it uses when oarcle apps webserver starts
when httpd starts it starts with
httpd.conf ( in Apache/Apache/conf ) This is main Apache configuration file which has configuration related to Main Apache Server like ServerName , port and Listen( I will discuss about these parameters in my next post tomorrow )
This httpd.conf file calls
jserv.conf ( in Apache/Jserv/etc ) for mod_jserv configuration ( All your Self Service servlets requests are via mod_jserv like discoverer view, xml services or OAM login (So you know now where to look if issue happens in these services , if not I will discuss this in my next post ) .
httpd.conf also include oracle_apache.conf ( in Apache/conf) for Oracle developed modules like mod_ossl, mod_pls .
httpd.conf also include oprocmgr.conf ( in Apache/conf) for Oprocmgr configuration. This module is used to identify remote apache instance that are sending requests to processes (Jserv ...), managed by local Apache Instance.
oracle_apache.conf ( which contain configuration file for modules developed by oracle like mod_pls..) . These files are plsql.conf (Apache/modplsql/cfg ) for mod_pls configuration.

I will discuss about httpd.conf parameters like port , access_log error_log where to look for Issues how to find errors & lot more in my next post here day after tomorrow .

Do you know you can tell who all accessed your applications at what time , how much time it took to get a page ?
How to tune Apache Web Server ?
How to check Jserv errors, your
JVM issues & how to start multiple JVM instance to increses your webserver capabilities ?
              Note:
                  apache conf directory  $IAS_ORACLE_HOME/Apache/Apache/conf
                  apache log directory   $IAS_ORACLE_HOME/Apache/Apache/logs

                  jserv etc directory    $IAS_ORACLE_HOME/Apache/Jserv/etc
                  jserv log directory    $IAS_ORACLE_HOME/Apache/Jserv/logs

jserv.conf — this is the configuration file of mod_jserv module in Apache.



Home page - http://11i-tst-02.cisco.com:38901 - working fine
Apps local login - http://11i-tst-02.cisco.com:38901/OA_HTML/AppsLocalLogin.jsp - throwing Java Exception
Servlet login - http://11i-tst-02.cisco.com:38901/oa_servlets/AppsLogin - throws Internal Server Erorr
Servlet test works - http://11i-tst-02.cisco.com:38901/servlets/Hello
OAM works - http://11i-tst-02.cisco.com:38901/servlets/weboam/oam/oamLogin - Navigating to SSO page for authentication
AOL test works - http://11i-tst-02.cisco.com:38901/OA_HTML/jsp/fnd/aoljtest.jsp
FND_WEB.PING works - http://11i-tst-02.cisco.com:38901/pls/QTCSTG/FND_WEB.PING
Connection test works - http://11i-tst-02.cisco.com:38901/servlets/oracle.apps.icx.common.ConnectionTest
  

No comments:

Post a Comment