[WSO2 ESB] All About Wire Logs..!

Intention of this post is to give you an idea of what you should know about wire logs in WSO2 ESB.

While working with ESB, sometimes we come across situations where we want see the actual http messages which goes out from the ESB or coming into the ESB. Wire logs functionality is there to fulfill that requirement.

Passthrough http transport is the main transport which handles http/https messages in WSO2 ESB. Following is how we can enable wire logs for Passthrough http transport.

Enabling wire logs

1. open log4j.properties file from a text editor.

log4j.properties file is located in /repository/conf directory.

2. Un-comment the following entry.

log4j.logger.org.apache.synapse.transport.http.wire=DEBUG

Above described procedure applies to WSO2 ESB 4.7.0 or higher versions.

Entry to un-comment in log4j.properties is slightly different in previous versions.

For ESB 4.6.0 :

log4j.logger.org.apache.synapse.transport.passthru.wire=DEBUG

For ESB 4.5.1 or previous versions :

log4j.logger.org.apache.synapse.transport.nhttp.wire=DEBUG

Reading wire logs

Following is a sample wire log get printed for the above scenario for a one request.

[2013-09-22 19:47:57,797] DEBUG - wire >> "POST /services/StockQuoteProxy HTTP/1.1[\r][\n]"

[2013-09-22 19:47:57,798] DEBUG - wire >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"

[2013-09-22 19:47:57,798] DEBUG - wire >> "SOAPAction: "urn:getQuote"[\r][\n]"

[2013-09-22 19:47:57,799] DEBUG - wire >> "User-Agent: Axis2[\r][\n]"

[2013-09-22 19:47:57,799] DEBUG - wire >> "Host: localhost:8280[\r][\n]"

[2013-09-22 19:47:57,799] DEBUG - wire >> "Transfer-Encoding: chunked[\r][\n]"

[2013-09-22 19:47:57,800] DEBUG - wire >> "[\r][\n]"

[2013-09-22 19:47:57,800] DEBUG - wire >> "215[\r][\n]"

[2013-09-22 19:47:57,800] DEBUG - wire >> "http://localhost:8280/services/StockQuoteProxyurn:uuid:9e1b0def-a24b-4fa2-8016-86cf3b458f67urn:getQuoteIBM[\r][\n]"

[2013-09-22 19:47:57,801] DEBUG - wire >> "0[\r][\n]"

[2013-09-22 19:47:57,801] DEBUG - wire >> "[\r][\n]"

[2013-09-22 19:47:57,846]  INFO - TimeoutHandler This engine will expire all callbacks after : 120 seconds, irrespective of the timeout action, after the specified or optional timeout

[2013-09-22 19:47:57,867] DEBUG - wire << "POST /services/SimpleStockQuoteService HTTP/1.1[\r][\n]"

[2013-09-22 19:47:57,867] DEBUG - wire << "Content-Type: text/xml; charset=UTF-8[\r][\n]"

[2013-09-22 19:47:57,867] DEBUG - wire << "SOAPAction: "urn:getQuote"[\r][\n]"

[2013-09-22 19:47:57,867] DEBUG - wire << "Transfer-Encoding: chunked[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "Host: localhost:9000[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "Connection: Keep-Alive[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "User-Agent: Synapse-PT-HttpComponents-NIO[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "215[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "http://localhost:8280/services/StockQuoteProxyurn:uuid:9e1b0def-a24b-4fa2-8016-86cf3b458f67urn:getQuoteIBM[\r][\n]"

[2013-09-22 19:47:57,868] DEBUG - wire << "0[\r][\n]"

[2013-09-22 19:47:57,869] DEBUG - wire << "[\r][\n]"

[2013-09-22 19:47:58,002] DEBUG - wire >> "HTTP/1.1 200 OK[\r][\n]"

[2013-09-22 19:47:58,002] DEBUG - wire >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"

[2013-09-22 19:47:58,002] DEBUG - wire >> "Date: Sun, 22 Sep 2013 14:17:57 GMT[\r][\n]"

[2013-09-22 19:47:58,002] DEBUG - wire >> "Transfer-Encoding: chunked[\r][\n]"

[2013-09-22 19:47:58,002] DEBUG - wire >> "Connection: Keep-Alive[\r][\n]"

[2013-09-22 19:47:58,002] DEBUG - wire >> "[\r][\n]"

[2013-09-22 19:47:58,014] DEBUG - wire << "HTTP/1.1 200 OK[\r][\n]"

[2013-09-22 19:47:58,015] DEBUG - wire << "Content-Type: text/xml; charset=UTF-8[\r][\n]"

[2013-09-22 19:47:58,015] DEBUG - wire << "Date: Sun, 22 Sep 2013 14:17:58 GMT[\r][\n]"

[2013-09-22 19:47:58,015] DEBUG - wire << "Server: WSO2-PassThrough-HTTP[\r][\n]"

[2013-09-22 19:47:58,016] DEBUG - wire << "Transfer-Encoding: chunked[\r][\n]"

[2013-09-22 19:47:58,016] DEBUG - wire << "[\r][\n]"

[2013-09-22 19:47:58,016] DEBUG - wire >> "4d8[\r][\n]"

[2013-09-22 19:47:58,017] DEBUG - wire >> "urn:getQuoteResponseurn:uuid:9e1b0def-a24b-4fa2-8016-86cf3b458f673.827143922330303-8.819296796724336-170.50810412063595170.73218944560944Sun Sep 22 19:47:57 IST 2013-170.472077024782785.562077973231586E7IBM Company178.0616712932281324.9438904049222641.9564266653777567195.61908401976004IBM6216[\r][\n]"

[2013-09-22 19:47:58,017] DEBUG - wire >> "0[\r][\n]"

[2013-09-22 19:47:58,018] DEBUG - wire >> "[\r][\n]"

[2013-09-22 19:47:58,021] DEBUG - wire << "4d8[\r][\n]"

[2013-09-22 19:47:58,022] DEBUG - wire << "urn:getQuoteResponseurn:uuid:9e1b0def-a24b-4fa2-8016-86cf3b458f673.827143922330303-8.819296796724336-170.50810412063595170.73218944560944Sun Sep 22 19:47:57 IST 2013-170.472077024782785.562077973231586E7IBM Company178.0616712932281324.9438904049222641.9564266653777567195.61908401976004IBM6216[\r][\n]"

[2013-09-22 19:47:58,022] DEBUG - wire << "0[\r][\n]"

[2013-09-22 19:47:58,022] DEBUG - wire << "[\r][\n]"

To read the wire log, first we have to identify message direction.

DEBUG - wire >>    - This represent the message coming into ESB from the wire

DEBUG - wire <<    - This represent the message goes to the wire from ESB

As you can see there are two incoming messages and two outgoing messages in the above log.

First part of the log of a message contain the http headers and it is followed by the message payload.

Wire logs are very useful when it comes to troubleshooting unexpected issues occurring while integrating systems. 

We can verify whether message payload is correctly going out from the ESB, http headers like Content-Type is properly set in the outgoing message, etc. by looking at the wire logs.

Please note that wire logs should be enabled for the troubleshooting purposes only. Running productions systems with wire logs enabled is not recommended.

Wire logs for Callout Mediator

Callout mediator uses the Axis2 CommonsHTTPSender to invoke services. It does not leverages the non blocking nhttp/passthrough transports. So to enable wire logs, we have to follow a different approach as follows.

1. open log4j.properties file from a text editor.

2. Put the following two entries to the log4j.properties.

log4j.logger.httpclient.wire.header=DEBUG

log4j.logger.httpclient.wire.content=DEBUG