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

Products

• CA Application Test
• CA Continuous Application Insight (PathFinder)
• Service Virtualization

Issue/Introduction

Would to log the time when each message is received and sent along with a timestamp for each. 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 could not be found.

 

Environment

All supported DevTest releases.

Cause

N/A

Resolution

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 " + mqSubQueue.name + ", ID: " + new 
String(Hex.encodeHex(msg.messageId))); 
>>
>> 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 " +
mqPubQueue.name); } try {
      mqPubQueue.put(mqSendMsg, pmo);
      if (log.isDebugEnabled()) {
   log.debug("Instance " + instanceName + ": Successfully sent message to " + mqPubQueue.name + ", ID (hex): " + new 	String
   (Hex.encodeHex(mqSendMsg.messageId)));
 }

 

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:

Step 1 : Create appender for MQ ( Lets name it as MQAPPENDER) Add this to existing appenders list in logging.properties

•  appenders = A1, ACL_LOG, VSEAPP, ADVICE_APP, THREAD_DUMPS, STDOUT, MQAPPENDER

Configure policies for MQAPPENDER 

• appender.MQAPPENDER.type = RollingFile
• appender.MQAPPENDER.name = MQAPPENDER
• appender.MQAPPENDER.fileName = ${LISA_HOME}/tmp/mq_messaging.log
• appender.MQAPPENDER.filePattern = ${sys:lisa.tmpdir}/mq_messaging.log.%i
• appender.MQAPPENDER.layout.type = PatternLayout
• appender.MQAPPENDER.layout.pattern = %d{ISO8601}{UTC}Z (%d{HH:mm}) [%t] %-5p %-30c - %m%n
• appender.MQAPPENDER.policies.type = Policies
• appender.MQAPPENDER.policies.size.type = SizeBasedTriggeringPolicy
• appender.MQAPPENDER.policies.size.size = 10MB
• appender.MQAPPENDER.strategy.type = DefaultRolloverStrategy
• appender.MQAPPENDER.strategy.max = 20
• appender.MQAPPENDER.strategy.fileIndex = min

 

Add this to your logging.properties in DevTest 10.7.2 and later

Step 2: Create logger for MQ ( lets name it as mqlogger) Add this to existing loggers list in logging.properties 

• loggers = teamdev, eventlogger, apache, smardec, apachehttp, mchange, hibernate, ….., mqlogger

Configure logger as below  

•  
• logger.mqlogger.name = com.itko.lisa.jms.mq.MQJavaEngine
• logger.mqlogger.level = DEBUG
• logger.mqlogger.additivity = false
• logger.mqlogger.appenderRefs= MQAPPENDER
• logger.mqlogger.appenderRef.MQAPPENDER.ref = MQAPPENDER

 

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