WebLogic Server: Logging the SOAP action in the access.log

WebLogic Server allows you to customize your access.log. This can be very powerful if you want to monitor for example service response times in a tool like Splunk (see here). When working with SOAP services though, especially those with many operations, it can be insufficient to monitor services to the level of the individual endpoint. You want to also know with which intent the endpoint is called. In this blog I will show how this can be achieved.

Extended Log File Format (ELFF)

The way you can add custom fields to the access.log is described here. This functionality has not changed noticeably for many releases of WebLogic Server. WebLogic Server supports the Extended Log File Format as described here. This can be configured by going to a server in WebLogic Console, Logging, HTTP. Click on Advanced and select Extended. Now you can specify additional fields like time-taken and bytes.

There is no custom field for the SOAP action available though.

Adding the SOAP Action field

WebLogic Server provides a feature to supply custom field identifiers. These have the simple format x-CustomFieldName where CustomFieldName is the fully qualified name of the class which provides the custom field.The class must implement the weblogic.servlet.logging.CustomELFLogger interface. Now we are nearly there.

Obtaining the SOAP action

The HTTP headers of a SOAP call often give an indication of the intent. For SOAP 1.1, the intent is supplied in the HTTP header field called SOAPAction. Filling this field is optional though. In SOAP 1.2 messages, the action parameter in the Content-Type header serves the same purpose. Often the intent gives a good indication of the operation which is called.

When implementing this logic in a custom class, it looks something like:

You can download the code here. Mind that the code is executed for every HTTP request going to the WebLogic Server so it is not recommended to write it in such a way that it can influence performance such as going to a DBMS or parsing entire messages. You should of course also mind that the function should return a value always, even in case of exceptions. It should thus be robust. If you don't, you might break the access.log format.

It is a JDeveloper 12.2.1 workspace but since the code is JDK 1.6 compliant, you can of course also use older versions of JDeveloper. Do mind to include WebLogic client libraries if you want to compile the project yourself. For ease of use, a JAR (compiled with JDK 1.6, usable for 11g and 12c) is also provided and a version which outputs a lot of information to System.out for debugging purposes. I have used Apache HttpComponents to make parsing the ContentType header easy.

Deploying the custom SOAPAction field

Copy the libraries in the deploy directory here (httpcore-4.4.6.jar and SOAPActionField.jar) to the DOMAINDIR/lib folder. As described above, enable Extended Log File Format and add the following field: x-nl.amis.customfield.SOAPActionField. Save your settings and restart the server. If you see a message like below, you have not put the JAR files in the correct directory.

<Error> <HTTP> <BEA-101234> <Attempting to initialize ExtendedLogFormat application specific header: x-nl.amis.customfield.SOAPActionField. However, initialization failed due to an exception.>

Testing

If you want to test this setting, you should test it with SOAP 1.1 and SOAP 1.2 services since the logic for determining the SOAP action differs. I have tested the custom SOAPActionField on SOA Suite composites and Service Bus running on WebLogic 11g and on 12c (12.2.1). Also, the access.log file is buffered. Batches of 8Kb are written at a time. For testing purposes, you can reduce this setting to 0. You can find it on the same page as the Extended Log settings. Fire up your favorite SOAP testing tool and send in some requests. Next check the access.log. Now you should see the SOAP action as the last field in this example.

Finally

If you want to do performance testing, it can be very useful to have time-taken, bytes and the soap action in the access.log. Luckily, with WebLogic Server, this can be easily achieved! It can also help to determine if requests to a certain operation often give HTTP responses other than code 200 (=OK). A drawback of using this method is a (very) slight performance impact and the SOAP action fields are optional in the SOAP 1.1 and 1.2 specification so some service or client implementations might not fill them in an expected way or not at all. SOA Suite does so nicely though. When using REST services, you of course do not need this since the resource is part of the URL and the HTTP verb is already present by default in the access.log.