Sunday, March 11, 2012

Configure Extended Logging In HTTP Access Logs For WebLogic Application Server

Hello There,

Most of us are aware that Access Logs Prints Application Access logs Information as below.

192.168.238.1 - - [01/Mar/2012:15:52:45 +0530] "GET /HelloWorld/welcome.jsp HTTP/1.1" 200 895
192.168.238.1 - - [01/Mar/2012:15:52:46 +0530] "GET /HelloWorld/GoodMorning.jsp HTTP/1.1" 200 2963


Which Specifically uses common logging format, syntax/format of the common logging format is as below.

host RFC931 auth_user [day/month/year:hour:minute:second UTC_offset] "request" status bytes.

The Above information is very limited in case if you need to know lot from it, each parameter above are specific to below information.

host
Either the DNS name or the IP number of the remote client
RFC931
Any information returned by IDENTD for the remote client; WebLogic Server does not support user identification
auth_user
If the remote client user sent a userid for authentication, the user name; otherwise "-"
day/month/year:hour:minute:second UTC_offset
Day, calendar month, year and time of day (24-hour format) with the hours difference between local time and GMT, enclosed in square brackets
"request"
First line of the HTTP request submitted by the remote client enclosed in double quotes
status
HTTP status code returned by the server, if available; otherwise "-"
bytes
Number of bytes listed as the content-length in the HTTP header, not including the HTTP header, if known; otherwise "-"

with the above information the access log is only used for to check whether application is being accessed or not over the server and the time and date of access, finally it will provide the status of the access.

Whereas the Extended Logging Format in WebLogic Server uses the W3C Specifications for the log format, for more information, please refer to http://www.w3.org/TR/WD-logfile.html

According to this logging format we can specify the customized fields for the HTTP Log file as in below link :

http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Library/IIS/676400bc-8969-4aa7-851a-9319490a9bbb.mspx?mfr=true

And : http://docs.oracle.com/cd/E13222_01/wls/docs91/config_wls/web_server.html#elf

Follow the below steps to configure the Extended Logging format for HTTP Logs.

 Step 1 : Install the WebLogic Server Software, Create a Domain, Start the Admin Server and Deploy a Sample Application to keep everything ready to test the Extended Logging format.

Step 2 : Click on Admin Server and Go to Logging Tab in the console

Step 3 : Click on HTTP to modify the HTTP logging format for the Application Access.

Step 4 : Scroll down and click on Advanced

Step 5 : Change the Format to Extended

Step 6 : And Specify the fields for Extended Logging in "Extended Logging Format Fields" as you would like to see the information from : http://docs.oracle.com/cd/E13222_01/wls/docs91/config_wls/web_server.html#elf




In my example domain I have specified the following fields.


date time cs-method cs-uri sc-status cs-username cs(User-Agent)  s-sitename s-ip s-port time-taken cs(Cookie) sc-substatus cs-host cs-version


So as per the above link it will provide us the information for : 

date : Date at which transaction completed, field has type <date>, as defined in the W3C specification. 

time : Time at which transaction completed, field has type <time>, as defined in the W3C specification.

cs-method : The request method, for example GET or POST. This field has type <name>, as defined in the W3C specification. 

cs-uri: The full requested URI. This field has type <uri>, as defined in the W3C specification. 

sc-status: Status code of the response, for example (404) indicating a "File not found" status. This field has type <integer>, as defined in the W3C specification.

cs-username: The name of the authenticated user who accessed your server. Anonymous users are indicated by a hyphen.

cs(User-Agent) : The browser type that the client used.

s-sitename: The Internet service name and instance number that was running on the client.

s-ip: The IP address of the server. 

s-port: The Port number of the server.

time-taken: Time taken for transaction to complete in seconds, field has type <fixed>, as defined in the W3C specification. 


cs(Cookie)
The content of the cookie sent or received, if any.

sc-substatus: The substatus error code.

cs-host: The host header name, if any.

cs-version: The protocol version —HTTP or FTP —that the client used.

After this has been specified, save the same and activate the changes.

Step 7: Restart the server to activate the changes.

Step 8 : Access the Application deployed over the server.

Step 9: View the Access logs created 

You will find following information sample in your access logs : 

#Version:    1.0
#Fields:    date time cs-method cs-uri sc-status cs-username cs(User-Agent)  s-sitename s-ip s-port time-taken cs(Cookie) sc-substatus cs-host cs-version
#Software:    WebLogic
#Start-Date:    2012-03-01    16:02:41
2012-03-01    10:33:22    GET    /helloworld/welcome.jsp    200    -    "Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20100101 Firefox/10.0.2"    -    192.168.238.1:7001    -    0.047    "JSESSIONID=QHclPPNTdXyGRJ5QRQFjC97t2PTnVKQTd2tB1hDVSFbf2pJNsw9t!-500938956"    -    -    -
2012-03-01    10:33:24    GET    /helloworld/hellothere    200    -    "Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20100101 Firefox/10.0.2"    -    192.168.238.1:7001    -    0.015    "JSESSIONID=wZDZPPQSqFY6n25mgNcZGsF2MmVxT05XQZ0vLnxqCltrJcYjt7nw!-1723970954"    -    -    -
2012-03-01    10:33:25    GET    /helloworld/hello.jsp    200    -    "Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20100101 Firefox/10.0.2"    -    192.168.238.1:7001    -    0.031    "JSESSIONID=wZDZPPQSqFY6n25mgNcZGsF2MmVxT05XQZ0vLnxqCltrJcYjt7nw!-1723970954"    -    -    -

You can check the each parameters and check for the log created, and cross check the information you have gathered.

Hope this posting was helpful for you.

Please share your feedback.

Regards
Shailesh Dyade

Thursday, March 1, 2012

Debugging WebLogic Server Process

Hello Folks,

Sometimes you will not understand what exactly the WebLogic Server thinks when it throws some Errors / Exceptions, WebLogic Server is Open enough that it will allow you to understand it completely at the microscopic level, but you got to have eyes and mind to understand it :).

Whenever WebLogic Server Works it will say what it is doing in very brief way by printing it over the logs like Server Logs, Access Logs, Domain logs, Diagnostics, etc.., However they are very specific and cannot print much more information for you to help unless you need them, as they have disadvantages too, one is you will have no more disk space in some days if you enable the trace level of logging.

But you might need this to be enabled for Debug Level to Understand few Operations of WebLogic Server, in this posting we will study how to enable the Debug Logging and How to Enable the Debugs for Cluster Component for Session Replication.

I have setup the WebLogic Server Version 10.3.0 at my labs and will configure and show it you how the Debugs Work.

Step 1.  Verify Running Servers are in Cluster for Enabling Replication Debugs - If you don't have clustered server there is no use of enabling Debug for Replication :)


Step 2 : Click on Server which needs Debug to be enabled.

For an instance click on Server1 -- Logging
Step 3: Scroll down and Click on Advanced

Step 4 : Select Severity Level as "Debug" for Server Log file, Standard Out, Minimum Severity to Log And Check the Check Box : "Redirect stdout logging enabled" -- Save it.

Step 5 : Repeat This For All the Server on which you need to know exactly how its behaving during the operation.

Note : This Configuration Change Requires Server Restart to Take Effect, Before We Restart the Servers, we will enable the Debugs for Session Replication.

Step 6 : Click On Debug Tab on Server Configuration Page.

Step 7: Expand "weblogic" -> "core" -->"cluster" Click on following Debugs and Click Enable.

--> DebugReplication
--> DebugReplicationDetails
--> DebugCluster - In Case if you think you might be running issue with cluster setup. 

Step 8 : Activate the Changes.

Step 9: Restart the Servers

Note : You can do all above operation in case if your managed servers are down also.

While you are starting the server, you can notice the Cluster Debugs as below.

####<Mar 1, 2012 9:22:53 AM IST> <Debug> <Cluster> <SDYADE-LAP> <Server1> <[STANDBY] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1330573973281> <BEA-000000> <Sending senderNum:0 seqNum:0 message:Heartbeat with 0 items outgoing message:message:[115, 114, 0, 33, 119, 101, 98, 108, 111, 103, 105, 99, 46, 99, 108, 117, 115, 116, 101, 114, 46, 72, 101, 97, 114, 116, 98, 101, 97, 116, 77, 101, 115, 115, 97, 103, 101, -98, -77, -6, 99, 112, -53, -92, -119, 12, 0, 0, 119, 2, 0, 0, 120, 112, 115, 114, 0, 19, 106, 97, 118, 97, 46, 117, 116, 105, 108, 46, 65, 114, 114, 97, 121, 76, 105, 115, 116, 120, -127, -46, 29, -103, -57, 97, -99, 3, 0, 1, 73, 0, 4, 115, 105, 122, 101, 119, 2, 0, 0, 120, 112, 0, 0, 0, 0, 119, 4, 0, 0, 0, 0, 120, 119, 8, 0, 0, 1, 53, -52, 99, -105, 33, 120, 0, 0, 0, 0, 0], size:123, seqNum:0, messageVersion:0,0,0>


Step 10: Deploy a Session Based Application to the cluster and Test the Application at Web Server Side and Test the Replication.

Step 11 : Shutdown the Server Where the Session is directed.

Debug for Debug Replication is as below : 

####<Mar 1, 2012 9:29:53 AM IST> <Debug> <Replication> <SDYADE-LAP> <Server2> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1330574393984> <BEA-000000> <Creating primary -3805878817075153326>
 

Debugs for the Replication details sample : 

####<Mar 1, 2012 9:29:53 AM IST> <Debug> <ReplicationDetails> <SDYADE-LAP> <Server2> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1330574393984> <BEA-000000> <Unable to create secondary for -3805878817075153326 on null>
####<Mar 1, 2012 9:29:54 AM IST> <Debug> <ReplicationDetails> <SDYADE-LAP> <Server2> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1330574394125> <BEA-000000> <Has secondary servers? false>
####<Mar 1, 2012 9:29:54 AM IST> <Debug> <ReplicationDetails> <SDYADE-LAP> <Server2> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1330574394125> <BEA-000000> <Current secondary server? null>


There seems to be some issue with the Secondary server creation for the session to be replicated, you can see that it has printed out the same message.


Now you are the Administrator, WebLogic Server has informed that what it is going through, please help it to help you to replicate the application session to the secondary server successfully.

Hope After this posting you are able to Debug the issues with different components too, keep trying.

Let me know if you need any more help.

Regards
Shailesh Dyade