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