AXIS Client Request and Response Logging

You have a Java application consuming a remote SOAP web service and you want to use AXIS 1.* framework. You want to see / log the raw SOAP request / response.

In a development or testing environment there are methods that don’t involve any configuration or code change for example a sniffer (if the TCP channel is not encrypted).

There are situations however when logging the soap requests and response/fault is needed in production on a continuous basis, usually for reconciliation purposes. In case of some integration issues, the party providing the service will want to see the actual SOAP messages.

The problem is solved by creating a custom handler and either register it programmatically, or use the client configuration file (WSDD).

I believe that adding a custom handler is not enough to justify attaching a client configuration file, therefore will show here the code related solution. BTW, the configuration oriented approach rather than the code based one reduces in my opinion the maintainability (you don't see what happens by looking at the code, you cannot add breakpoints everywhere etc).

The steps are as follows:

  • Obtain the WSDL document. Copy it locally if you don’ t mind and refer to the local copy when generating the client, so that the project will build even if you are not connected to internet.
  • Generate the client by using org.apache.axis.tools.ant.wsdl.Wsdl2javaAntTask ant task
  • Compile the generated code then pack everything in a jar file for easy handling (“client.jar”)
  • Create a class implementing javax.xml.rpc.handler.GenericHandler
  • Register the class in the client

For testing purposes I found a test web service published on web that does some simple math calculation. The WSDL was from the url http://soaptest.parasoft.com/calculator.wsdl. The service endpoint is at the url http://ws1.parasoft.com/glue/calculator.

Although I don’t want to get in details about how to actually generate the classes, here is the build script I used:

  1.  
  2. <project name="client" default="all" basedir="..">
  3. <property name="temp.folder" value="./temp" />
  4. <property name="compile.folder" value="./compile" />
  5. <property name="client.jar" value="./build-jar/client.jar" />
  6.  
  7. <path id="all.path">
  8. <fileset dir="./lib" />
  9. </path>
  10.  
  11. <taskdef name="wsdl2java" classname="org.apache.axis.tools.ant.wsdl.Wsdl2javaAntTask" classpathref="all.path" />
  12.  
  13. <target name="all">
  14. <delete dir="${temp.folder}" />
  15. <delete dir="${compile.folder}" />
  16.  
  17. <mkdir dir="${temp.folder}" />
  18. <mkdir dir="${compile.folder}" />
  19.  
  20. <wsdl2java verbose="true" debug="true" url="./config/client.wsdl" output="${temp.folder}"/>
  21. <javac srcdir="${temp.folder}" destdir="${compile.folder}" classpathref="all.path" />
  22.  
  23. <copy todir="${compile.folder}">
  24. <fileset dir="${temp.folder}">
  25. <exclude name="**/*.java" />
  26. </fileset>
  27. </copy>
  28.  
  29. <delete file="${client.jar}" />
  30.  
  31. <jar jarfile="${client.jar}">
  32. <fileset dir="${compile.folder}" />
  33. </jar>
  34.  
  35. <delete dir="${temp.folder}" />
  36. <delete dir="${compile.folder}" />
  37. </target>
  38. </project>
  39.  
  40.  

I had issues generating the client, that were fixed by removing all the occurences of the attribute parameterOrder in the WSDL.

The port type used has the QName with the following parameters:

  • Namespace: http://www.parasoft.com/wsdl/calculator/
  • Name: ICalculator

The approach without the logging handler

Following is the code:

1    package com.proghowto.wsclient.test;
2    
3    import java.net.MalformedURLException;
4    import java.net.URL;
5    import java.rmi.RemoteException;
6    
7    import javax.xml.rpc.ServiceException;
8    
9    import com.parasoft.www.wsdl.calculator.CalculatorLocator;
10   import com.parasoft.www.wsdl.calculator.ICalculator;
11   
12   public class TestClient {
13       public static void main(String[] args) {
14           try {
15               new TestClient().start();
16           }
17           catch(Exception e){
18               e.printStackTrace();
19           }
20       }
21   
22       private void start() throws MalformedURLException, ServiceException, RemoteException {
23           // get the web service locator and then the service instance. 
24           // The url of the endpoint is provided
25           CalculatorLocator locator = new CalculatorLocator();
26           ICalculator service = locator.getICalculator(new URL("http://ws1.parasoft.com/glue/calculator"));
27           
28           // we calculate the total between two float parameters
29           float x = 12.21f;
30           float y = 3.35f;
31           
32           // call the web service
33           float result = service.add(x, y);
34           
35           // and here is the result
36           print("x = " + x);
37           print("y = " + y);
38           print("res = " + result);
39       }
40   
41       private void print(Object current) {
42           System.out.println(current);
43       }
44   }
45   

Now, assuming we created the class TestHandler that extends GenericHandler, this is how we write the actual client invocation:

void start() throws MalformedURLException, ServiceException, RemoteException {
28           CalculatorLocator locator = new CalculatorLocator();
29           HandlerRegistry handlerRegistry = locator.getHandlerRegistry();
30           QName qname = new QName("http://www.parasoft.com/wsdl/calculator/", "ICalculator");
31           
32           @SuppressWarnings("rawtypes")
33           List chain = handlerRegistry.getHandlerChain(qname);
34           
35           HandlerInfo info = new HandlerInfo();
36           info.setHandlerClass(TestHandler.class);
37           
38           chain.add(info);
39           
40           ICalculator service = locator.getICalculator(new URL("http://ws1.parasoft.com/glue/calculator"));
41           
42           float x = 12.21f;
43           float y = 3.35f;
44           
45           float result = service.add(x, y);
46           
47           print("x = " + x);
48           print("y = " + y);
49           print("res = " + result);
50       }

Please note the following:

  • The handler registry instance is retrieved from the locator
  • The handler list is filtered to retrieve only the ones associated to the port type in use. The port type is specified by the fully qualified QName (namespace and name).
  • The TestHandler class is registered by being wrapped in an instance of javax.xml.rpc.handler.HandlerInfo. A new instance of TestHandler is created every time a service call is placed through the indicated port type.

And now the handler class. Basically there are three methods we are interested in, handleFault, handleRequest, handleResponse. All three methods give the opportunity to change the message on the fly, nevertheless our purpose is to only log it.

Here is the full class. I used logging to stdout for testing purposes, in production will replace this with a call to log4j.

1    package com.proghowto.wsclient.test;
2    
3    import java.io.ByteArrayOutputStream;
4    
5    import javax.xml.namespace.QName;
6    import javax.xml.rpc.handler.GenericHandler;
7    import javax.xml.rpc.handler.MessageContext;
8    import javax.xml.rpc.handler.soap.SOAPMessageContext;
9    
10   public class TestHandler extends GenericHandler {
11   
12       private static final long serialVersionUID = -1088299597212448917L;
13       private String timeStamp;
14       
15       public TestHandler(){
16           timeStamp = Long.toString(System.currentTimeMillis());
17       }
18   
19       @Override
20       public QName[] getHeaders() {
21           return null;
22       }
23   
24       @Override
25       public boolean handleFault(MessageContext context) {
26           System.out.println(timeStamp + "_fault: " + getStringMessage(context));
27           
28           return super.handleFault(context);
29       }
30       
31       private String getStringMessage(MessageContext context){
32           String res = null;
33           
34           try {
35               SOAPMessageContext ctx = (SOAPMessageContext) context;
36               
37               ByteArrayOutputStream stream = new ByteArrayOutputStream();
38               ctx.getMessage().writeTo(stream);
39               byte[] items = stream.toByteArray();
40               
41               res = new String(items);
42           }
43           catch(Exception e){
44               // nothing - just ensuring the method will not throw an exception in case something is wrong.
45           }
46   
47           return res;
48       }
49   
50       @Override
51       public boolean handleRequest(MessageContext context) {
52           System.out.println(timeStamp + "_request: " + getStringMessage(context));
53           
54           return super.handleRequest(context);
55       }
56   
57       @Override
58       public boolean handleResponse(MessageContext context) {
59           System.out.println(timeStamp + "_response: " + getStringMessage(context));
60           
61           return super.handleResponse(context);
62       }
63   
64   }
65   

Here are a logged request and response (for readability I added some new lines, however normally they were on one line both of them)

Request

1325213680787_request: <?xml version="1.0" encoding="UTF-8"?>
<soapenv:Envelope 
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" 
xmlns:xsd="http://www.w3.org/2001/XMLSchema" 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
<soapenv:Body><add xmlns="http://www.parasoft.com/wsdl/calculator/">
<x>12.21</x><y>3.35</y></add>
</soapenv:Body></soapenv:Envelope>

Response

1325213680787_response: <?xml version="1.0" encoding="UTF-8"?>
<soap:Envelope 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" 
xmlns:xsd="http://www.w3.org/2001/XMLSchema" 
xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
<soap:Body><n:addResponse xmlns:n="http://www.parasoft.com/wsdl/calculator/">
<n:Result xsi:type="xsd:float">15.559999</n:Result></n:addResponse>
</soap:Body></soap:Envelope>

Final notes

Log one artifact on one line only

You want to ensure that whatever you log (request, response, fault) will be logged on one line only, or else, in a multithreaded environment it will be difficult to tell the lines from a transaction from the ones from another transaction. Search for any end of line in the logged result and change it to something else, like \N or similar.

Pair the transaction artifacts

Usually for one transaction there are two items logged, either the request and the response, or the request and the fault. You need a reliable method to pair the two artifacts.

A solution: for each transaction, a new instance of the handler (here TestHandler) is created. I created a class attribute that is initialized with some unique value in the class constructor and then ensured this is logged together with the request, response or fault. In our case, for simplicity, I chose system timestamp as the attribute value, however in production you should go for something really unique, like a random guid generator - one can be found here