Debugging SOAP by logging the incoming HttpRequest

24 Aug

As I described here I had a situation in which we wanted to be able to store all incoming SOAP requests for debugging purposes. The thing that made it a little tricky was that the logging had to be done before the request reached the XFire servlet and after JBoss had decoded the request (it is sent using https) and made it readable for us, humans.
Now I am aware of the HTTPtunnelers and other tools out there that could be used for this, but to find one that works according to our demands and to find out how it works, we decided it would easier/quicker to create a Filter and use that for our needs.
I don’t know about you, but this is really a thing that just has to go wrong with the first attempt. The idea we had for the filter was to do something like this:

  • get the request
  • get the inputstream
  • log the inputstream to log file
  • continue the normal process

So we build a filter with the following code (only the main part is shown):

public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
         throws IOException, ServletException {

      InputStream is = request.getInputStream();
      LOG.info( slurp(is));
      is.close();
      chain.doFilter(request, response);
   }

   private String slurp(InputStream is) throws IOException {
      StringBuffer out = new StringBuffer();
      byte[] b = new byte[4096];
      for (int n; (n = is.read(b)) != -1;) {
          out.append(new String(b, 0, n));
      }
      return out.toString();
  }

When you try this implementation of the filter you will definitely receive errors in your web service! This is caused by the fact that the inputstream is already processed in the filter so you can not process it again in your web service/servlet: it just doesn’t receive a body of the request anymore.
After we realized this, I remembered an example of the book ‘Head First Servlets and JSP’. In that book they have a similar problem and to solve it they make their own implementation of the HttpServletRepsonse by constructing a wrapper around the original one. We quickly realized we had to do the same thing here but then for the request. So what we will do in our filter implementation is that we will pass an instance of our LoggingRequest to the chain. In our loggingRequest everything that is read from the inputstream is copied to a stringbuffer and when we get back in our filter (when the reponse is sent back to the client) we get the content of that stringbuffer and we have our desired output. Sounds nice, huh? Well, here is the code of the whole filter:

package net.pascalalma.filter;

import java.io.IOException;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletInputStream;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

public class LogRequestFilter implements Filter {

   private static final Log LOG = LogFactory.getLog(LogRequestFilter.class);

   /**
    * DoFilter method.
    */
   public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
         throws IOException, ServletException {
      LoggingRequest req = new LoggingRequest((HttpServletRequest)request);
      chain.doFilter(req, response);
      LOG.info(req.getPayload());
   }

   /**
    * Init method.
    */
   public void init(FilterConfig config) throws ServletException {
   }

   /**
    * Destroy method.
    */
   public void destroy() {
   }

   /* Private class definitions */
   private class LoggingRequest extends HttpServletRequestWrapper {

      private LoggingInputStream is;

      public LoggingRequest(HttpServletRequest request) throws IOException {
         super(request);
         this.is = new LoggingInputStream(request.getInputStream());
      }

      @Override
      public ServletInputStream getInputStream() throws IOException {
         return is;
      }

      public String getPayload() {
         return is.getPayload();
      }
   }

   private class LoggingInputStream extends ServletInputStream {

      private StringBuffer bfr = new StringBuffer();
      private ServletInputStream is;

      public LoggingInputStream(ServletInputStream is) {
         super();
         this.is = is;
      }

      // Since we are not sure which method is used just overwrite all 4 of them:
      @Override
      public int read() throws IOException {
         int ch = is.read();
         if (ch != -1) {
            bfr.append((char)ch);
         }
         return ch;
      }

      @Override
      public int read(byte[] b) throws IOException {
         int ch = is.read(b);
         if (ch != -1) {
            for (byte byteSingle: b )
              bfr.append( (char)byteSingle);
         }
         return ch;
      }

      @Override
      public int read(byte[] b, int o, int l) throws IOException {
         int ch = is.read(b,o,l);
         if (ch != -1) {
            for (byte byteSingle: b )
               bfr.append( (char)byteSingle);

         }
         return ch;
      }
      @Override
      public int readLine(byte[] b, int o, int l) throws IOException {
         int ch = is.readLine(b,o,l);
         if (ch != -1) {
            bfr.append(b);
         }
         return ch;
      }

      public String getPayload() {
         return bfr.toString();
      }
   }
}

So although it took a little longer then we had planned, it sure was fun to do ;-)

9 Responses to “Debugging SOAP by logging the incoming HttpRequest”

  1. Mykola Dzyuba 29/08/2007 at 23:46 #

    In response to this comment: “When you try this implementation of the filter you will definitely receive errors in your web service! This is caused by the fact that the inputstream is already processed in the filter so you can not process it again in your web service/servlet”

    I think it would be easier to simply call in.reset() as it is done in my function below.

    private void writeInputStream(HttpServletRequest request, BufferedWriter out) throws IOException {
    out.write(“** START INPUTSTREAM **n”);
    ServletInputStream in = request.getInputStream();
    if (in.markSupported()) {
    in.mark(MAX_BYTES);
    }
    int i = 0;
    while ((i = in.read()) != -1) {
    out.write(i);
    }
    out.write(“n** END OF INPUTSTREAM **n”);
    in.reset();
    }

  2. Pascal Alma 30/08/2007 at 05:57 #

    LOL!
    I don’t have time right now to check this but if it is true then that would be a much easier solution!
    So if this blog isn’t helpful to you, at least I am learning of it :-)

  3. Pascal Alma 18/09/2007 at 06:48 #

    Just got some time to test the filter with the reset() statement. Unfortunatly it doesn’t work. I’m getting the following stacktrace:
    java.io.IOException: mark/reset not supported
    java.io.InputStream.reset(InputStream.java:331)
    net.pascalalma.filter.LogRequestFilter.doFilter(LogRequestFilter.java:51)
    org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)

    So maybe my solution wasn’t that bad??

  4. jim 31/10/2007 at 19:45 #

    Thank you Pascal. This is exactly what I was looking for as I was at dead end wondering why the SOAP servcie was blowing up just because I logged the inputstream. Your idea is great and I appreciate you posting your solution. I was in the exact same situation. It tried as the other comment suggests about using .reset() and it didn’t work for me either, but your solution did work great. Thanks again!

  5. mat 22/11/2007 at 10:41 #

    The sample kind of works but for some reason the logged SOAP request gets truncated towards the end. I could not detect the reason. Pretty odd. Any idea why that would be ?
    Thank you anyway.

  6. Tom Hunt 25/11/2007 at 21:21 #

    Pascal,
    Thank you! I have been trying to implement the same solution for logging multipart-form data posts. I tried wrapping the request, but I hadn’t taken it to the point of overriding the inputstream and its read functions. This works like a charm.

  7. Zouq 01/12/2007 at 11:01 #

    Any idea how to log outgoing Response??? Any help would be appreciated.

  8. netminkey 20/12/2007 at 20:44 #

    You could also wrap the request in an HttpServletRequestWrapper:

    class MyWrapper extends javax.servlet.HttpServletRequestWrapper {
    private ServletInputStream wrappedInputStream;
    public MyWrapper(HttpServletRequest servletRequest)
    { super(servletRequest); }

    public void printInputStream() throws IOException {
    InputStream s = getRequest().getInputStream();
    byte[] data = null;
    try { data = readDataIntoByteArray(s); }
    finally { s.close(); }
    System.out.println(“Data is: ” + new String(data));

    final ByteArrayInputStream bis = new ByteArrayInputStream(data);
    wrappedInputStream = new ServletInputStream() {
    @Override
    public int read() throws IOException
    { return bis.read(); }};
    }
    @Override
    public ServletInputStream getInputStream() throws IOException {
    if (wrappedInputStream == null)
    return getRequest().getInputStream();
    else
    return wrappedInputStream;
    }
    }

    and use it like this:
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
    MyWrapper httpRequest = new MyWrapper((HttpServletRequest)request);
    httpRequest.printInputStream();
    chain.doFilter(httpRequest, response);
    }

    Even better, you can add an init param to your filter to choose whether to turn debugging on (for dev mode) or off (for production mode)

  9. netminkey 20/12/2007 at 23:36 #

    or more simply:

    public void init(FilterConfig filterConfig) throws ServletException
    {
    com.sun.xml.ws.transport.http.HttpAdapter.dump=true;
    }

Comments are closed.

Follow

Get every new post delivered to your Inbox.

Join 97 other followers

%d bloggers like this: