IBM MQ - How do I log the time when each message is received and sent along with a timestamp for each?

Document ID : KB000048419
Last Modified Date : 14/02/2018
Show Technical Document Details

Issue to be Resolved:

They would like us to log the time when each message is received and sent along with a timestamp for each. They want to track each message through the model and match them to the app send and receive times. Somewhere along the path from the app through the MQ's and in the vs model there's a 3-second delay they cannot find.

Technical Challenges:

Preferred Approach:

The preferred approach is to use the logging that is provided in the messageId at debug level:

log.debug("Instance " + instanceName + ": Successfully received     
message from " + + ", ID: " + new 
>> and we log the correlID to the same logger just before we send a message:
log.debug("Instance " + instanceName + ": Setting correlation ID to
(hex): " + new String(Hex.encodeHex((byte[]) byteProp)));
>> before sending it:
if (log.isDebugEnabled()) {
     log.debug("Instance " + instanceName + ": Sending message to " +; } try {
      mqPubQueue.put(mqSendMsg, pmo);
      if (log.isDebugEnabled()) {
   log.debug("Instance " + instanceName + ": Successfully sent message to " + + ", ID (hex): " + new 	String

Approach not taken:

Possible approach to resolve problem is saving the responses and applying an XML filter to extract the desired values but your approach sounds like it will provide the results.

Not the best approach since it would result in a Heisenberg issue where the XML filter is dragging down the performance (XPath does not generate great performance).

How to Implement Preferred Approach:

Add this to your, MQAPPENDER       
 log4j.appender.MQAPPENDER =org.apache.log4j.RollingFileAppender 
 log4j.appender.MQAPPENDER.layout.ConversionPattern=%d [%t] %-5p - %m%n

That will redirect all the MQ-related logging to its own file, which will simplify things.