Monday, March 16, 2015

How to get wire logs from WSO2 ESB

When working with WSO2 Enterprise Service Bus, sometimes we need to see/analyze the HTTP messages coming to ESB and going out from ESB.

Without installing third party software to view these messages we can use WSO2 ESB built-in wire log functionality.

By enabling wire logs for Passthrough http transport in ESB we can easily exploit this capability.
I'm using ESB 4.8.0 for my testing in this article.

WSO2 ESB Configuration changes

Here are the steps to enable wire logs in ESB.

1. Open log4j.properties file from terminal.
> vi <ESB_HOME>/repository/conf/log4j.properties

2. Find the following line, comment out and save the changes to the log4j.properties file.
log4j.logger.org.apache.synapse.transport.http.wire=DEBUG

3. Start/Restart ESB server
> sh <ESB_HOME>/bin/wso2server.sh

Now you are ready to view wire logs from WSO2 ESB.

Creating a service request and getting the response

I have used the echo proxy in WSO2 ESB for my testing.



Using SOAP UI, I have sent the following SOAP message to the WSO2 ESB echo proxy service [1] SOAP endpoint.

<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:echo="http://echo.services.core.carbon.wso2.org">
   <soapenv:Header/>
   <soapenv:Body>
      <echo:echoString>
         <in>Suhan says hi!</in>
      </echo:echoString>
   </soapenv:Body>
</soapenv:Envelope>

I got the following response from ESB echo proxy service.

<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/">
   <soapenv:Body>
      <ns:echoStringResponse xmlns:ns="http://echo.services.core.carbon.wso2.org">
         <return>Suhan says hi!</return>
      </ns:echoStringResponse>
   </soapenv:Body>
</soapenv:Envelope>

Reading the wire logs from WSO2 ESB console

Following is the output from the WSO2 ESB console I have obtained.

[2015-03-16 16:36:16,665] DEBUG - wire >> "POST /services/echo.echoHttpSoap11Endpoint HTTP/1.1[\r][\n]"
[2015-03-16 16:36:16,668] DEBUG - wire >> "Accept-Encoding: gzip,deflate[\r][\n]"
[2015-03-16 16:36:16,668] DEBUG - wire >> "Content-Type: text/xml;charset=UTF-8[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "SOAPAction: "urn:echoString"[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "Content-Length: 317[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "Host: Suhans-MacBook-Pro.local:8280[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "Connection: Keep-Alive[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "User-Agent: Apache-HttpClient/4.1.1 (java 1.5)[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "[\r][\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:echo="http://echo.services.core.carbon.wso2.org">[\n]"
[2015-03-16 16:36:16,669] DEBUG - wire >> "   <soapenv:Header/>[\n]"
[2015-03-16 16:36:16,670] DEBUG - wire >> "   <soapenv:Body>[\n]"
[2015-03-16 16:36:16,670] DEBUG - wire >> "      <echo:echoString>[\n]"
[2015-03-16 16:36:16,670] DEBUG - wire >> "         <!--Optional:-->[\n]"
[2015-03-16 16:36:16,670] DEBUG - wire >> "         <in>Suhan says hi!</in>[\n]"
[2015-03-16 16:36:16,670] DEBUG - wire >> "      </echo:echoString>[\n]"
[2015-03-16 16:36:16,670] DEBUG - wire >> "   </soapenv:Body>[\n]"
[2015-03-16 16:36:16,671] DEBUG - wire >> "</soapenv:Envelope>"
[2015-03-16 16:36:16,726] DEBUG - wire << "HTTP/1.1 200 OK[\r][\n]"
[2015-03-16 16:36:16,726] DEBUG - wire << "Content-Type: text/xml; charset=UTF-8[\r][\n]"
[2015-03-16 16:36:16,726] DEBUG - wire << "Date: Mon, 16 Mar 2015 11:06:16 GMT[\r][\n]"
[2015-03-16 16:36:16,727] DEBUG - wire << "Server: WSO2-PassThrough-HTTP[\r][\n]"
[2015-03-16 16:36:16,727] DEBUG - wire << "Transfer-Encoding: chunked[\r][\n]"
[2015-03-16 16:36:16,727] DEBUG - wire << "Connection: Keep-Alive[\r][\n]"
[2015-03-16 16:36:16,727] DEBUG - wire << "[\r][\n]"
[2015-03-16 16:36:16,730] DEBUG - wire << "125[\r][\n]"
[2015-03-16 16:36:16,730] DEBUG - wire << "<?xml version="1.0" encoding="UTF-8"?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><ns:echoStringResponse xmlns:ns="http://echo.services.core.carbon.wso2.org"><return>Suhan says hi!</return></ns:echoStringResponse></soapenv:Body></soapenv:Envelope>[\r][\n]"
[2015-03-16 16:36:16,731] DEBUG - wire << "0[\r][\n]"
[2015-03-16 16:36:16,731] DEBUG - wire << "[\r][\n]"

Now lets see how to identify the message direction from this console output.
As you may already know there have to be messages coming to ESB from wire and going out to wire from ESB.

Following indicates the messages coming to ESB from wire.
DEBUG - wire >> "POST /services...... 

Following indicates the messages going to wire from ESB.
DEBUG - wire << "HTTP/1.1 200 OK.......

Why see wire logs?
  • Troubleshoot unexpected issues in integrated systems. 
  • Whether the correct payload is going out from ESB. e.g.: Whether the Content-type HTTP headers are properly set in out going messages.
  • Whether the correct SOAP messages coming to ESB. e.g.: Corrupted, malformed...


Note: This configuration change only applicable to WSO2 ESB 4.7.0 or higher versions.

Note: We DO NOT recommend running production systems with wire logs enabled. Wire logs should be enabled ONLY for the troubleshooting purposes.

[1] http://suhans-macbook-pro.local:8280/services/echo?wsdl