MQSeries.net :: View topic - Aggregate Flow Not Finding Original Message

EricCox · Posted: Fri Apr 08, 2011 9:12 am Post subject:

Could someone help me figure out why my AGG_RS flow is not finding the original message and allowing the message to flow into the MAIN_RS_FLOW

I am using AggregateControl, AggregateRequest and AggregateReply to handle timeout issues only.

I have:
ServiceConsumer>>>AGG_RQ>>>MAIN_RQ_FLOW
ServiceDelivery>>>AGG_RS>>>MAIN_RS_FLOW>>>ServiceConsumer

The AGG_RQ uses the AggregateControl to set the timeout and has a AggregateRequest node setting the folder on its way out to the MAIN_RQ_FLOW.

The AGG_RS flow does not find the original message and does not allow the message to flow to the MAIN_RS_FLOW.

Here are the sections of the trace that catch my eye.

Here it looks like as I propogate the message to the storage queue the AGG_RS flow tries to pick it up at the same time the main
request flow begins to process.

2011-04-08 08:43:25.011137 11348 UserTrace BIP2537I: Node 'TLR_AGG_RQ.Propagate Orig Msg': Executing statement ''RETURN TRUE;'' at ('.TLR_AGG_RQ_Propogate_Orig_Msg.Main', '10.3').
2011-04-08 08:43:25.011234 11348 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'TLR_AGG_RQ.Propagate Orig Msg'.
2011-04-08 08:43:25.054632 11348 UserTrace BIP2638I: The MQ output node 'TLR_AGG_RQ.IAB.TLR.AGG.ORIG.RQ.IN' attempted to write a message to queue ''IAB.TLR.AGG.ORIG.RQ.IN'' connected to queue manager ''''. The MQCC was '0' and the MQRC was '0'.
2011-04-08 08:43:25.054731 11348 UserTrace BIP2622I: Message successfully output by output node 'TLR_AGG_RQ.IAB.TLR.AGG.ORIG.RQ.IN' to queue ''IAB.TLR.AGG.ORIG.RQ.IN'' on queue manager ''''.
2011-04-08 08:43:25.205026 1492 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'TLR_AGG_RS.IAB.TLR.AGG.ORIG.RQ.IN'.
2011-04-08 08:43:25.205795 1492 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'TLR_AGG_RS.IAB.TLR.AGG.ORIG.RQ.IN' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-04-08 08:43:25.207307 1492 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'TLR_AGG_RS.IAB.TLR.AGG.ORIG.RQ.IN' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-04-08 08:43:25.207479 1492 UserTrace BIP6061I: Parser type ''BLOB'' created on behalf of node 'TLR_AGG_RS.IAB.TLR.AGG.ORIG.RQ.IN' to handle portion of incoming message of length '3926' bytes beginning at offset '364'. Parser type selected based on value ''NONE'' from previous parser.
2011-04-08 08:43:25.210180 4396 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'TLR_RQ.IAB.TLR.MONETARY.RQ.IN'.
2011-04-08 08:43:25.212095 4396 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'TLR_RQ.IAB.TLR.MONETARY.RQ.IN' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-04-08 08:43:25.213127 1492 UserTrace BIP2537I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Executing statement ''BEGIN ... END;'' at ('.TLR_AGG_RS_CopyMsgIdToCorellId.main', '1.41').
2011-04-08 08:43:25.213312 1492 UserTrace BIP2537I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Executing statement ''SET OutputRoot = InputRoot;'' at ('.TLR_AGG_RS_CopyMsgIdToCorellId.main', '2.3').
2011-04-08 08:43:25.213378 4396 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'TLR_RQ.IAB.TLR.MONETARY.RQ.IN' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-04-08 08:43:25.213483 1492 UserTrace BIP2539I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Evaluating expression ''InputRoot'' at ('.TLR_AGG_RS_CopyMsgIdToCorellId.main', '2.20'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2011-04-08 08:43:25.213550 1492 UserTrace BIP2568I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Copying sub-tree from ''InputRoot'' to ''OutputRoot''.
2011-04-08 08:43:25.214057 1492 UserTrace BIP2537I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Executing statement ''SET OutputRoot.MQMD.CorrelId = InputRoot.MQMD.MsgId;'' at ('.TLR_AGG_RS_CopyMsgIdToCorellId.main', '4.3').
2011-04-08 08:43:25.214136 1492 UserTrace BIP2539I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Evaluating expression ''InputRoot.MQMD.MsgId'' at ('.TLR_AGG_RS_CopyMsgIdToCorellId.main', '4.34'). This resolved to ''InputRoot.MQMD.MsgId''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='MsgId' Value=X'414d5120514d424b524430312020202034ef774d238ebc03'''.
2011-04-08 08:43:25.214206 1492 UserTrace BIP2568I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Copying sub-tree from ''InputRoot.MQMD.MsgId'' to ''OutputRoot.MQMD.CorrelId''.
2011-04-08 08:43:25.214307 1492 UserTrace BIP2537I: Node 'TLR_AGG_RS.CopyMsgIdToCorelId': Executing statement ''RETURN TRUE;'' at ('.TLR_AGG_RS_CopyMsgIdToCorellId.main', '5.3').
2011-04-08 08:43:25.214391 1492 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'TLR_AGG_RS.CopyMsgIdToCorelId'.
2011-04-08 08:43:25.219575 4396 UserTrace BIP6061I: Parser type ''XML'' created on behalf of node 'TLR_RQ.IAB.TLR.MONETARY.RQ.IN' to handle portion of incoming message of length '3951' bytes beginning at offset '364'. Parser type selected based on value ''XML'' from previous parser.
2011-04-08 08:43:25.233001 4396 UserTrace BIP2537I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Executing statement ''BEGIN ... END;'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '1.40').
2011-04-08 08:43:25.233095 4396 UserTrace BIP2537I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Executing statement ''SET OutputRoot = InputRoot;'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '2.1').
2011-04-08 08:43:25.233161 4396 UserTrace BIP2539I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Evaluating expression ''InputRoot'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '2.18'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2011-04-08 08:43:25.233213 4396 UserTrace BIP2568I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Copying sub-tree from ''InputRoot'' to ''OutputRoot''.
2011-04-08 08:43:25.236980 4396 UserTrace BIP2537I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Executing statement ''DECLARE startTime INTERVAL;'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '4.1').
2011-04-08 08:43:25.237041 4396 UserTrace BIP2537I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Executing statement ''SET startTime = CURRENT_GMTTIMESTAMP - GMTTIMESTAMP '2002-01-01 00:00:00';'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '7.1').
2011-04-08 08:43:25.238597 4396 UserTrace BIP2540I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Finished evaluating expression ''CURRENT_GMTTIMESTAMP'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '7.18'). The result was ''GMTTIMESTAMP '2011-04-08 12:43:25.211535'''.
2011-04-08 08:43:25.247583 1492 UserTrace BIP4412I: Corresponding request record not found for the reply message.
An AggregateReply node has received a message at its 'in' terminal. No corresponding record of a request message being sent could be found. See subsequent messages to determine how this situation has been handled.
It is possible that extraneous messages are arriving at the AggregateReply node 'in' terminal. Check your flow to ensure that the only messages arriving here are replies to request messages previously sent out and passed through an AggregateRequest node. It is possible that this message is a valid reply but part of an aggregation which previously timed out. It is possible that this is a reply to a message which has not yet been recorded by an AggregateRequest node. This can happen if request messages are sent outside of transactional control. Adjust your transaction settings to ensure that messages are sent under transactional control.
2011-04-08 08:43:25.255105 4396 UserTrace BIP2539I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Evaluating expression ''CURRENT_GMTTIMESTAMP - GMTTIMESTAMP '2002-01-01 00:00:00''' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '7.39'). This resolved to ''GMTTIMESTAMP '2011-04-08 12:43:25.211535' - GMTTIMESTAMP '2002-01-01 00:00:00'''. The result was ''INTERVAL '292423405.211535' SECOND''.
2011-04-08 08:43:25.255231 4396 UserTrace BIP2537I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Executing statement ''SET Environment.TimingData.StartTime = startTime;'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '8.1').
2011-04-08 08:43:25.255332 4396 UserTrace BIP2539I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Evaluating expression ''startTime'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '8.46'). This resolved to ''startTime''. The result was ''INTERVAL '292423405.211535' SECOND''.
2011-04-08 08:43:25.255405 4396 UserTrace BIP2566I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Assigning value ''INTERVAL '292423405.211535' SECOND'' to field / variable ''Environment.TimingData.StartTime''.
2011-04-08 08:43:25.255458 4396 UserTrace BIP2537I: Node 'TLR_RQ.CalcStartTime.CalcStartTime': Executing statement ''RETURN TRUE;'' at ('.CalcStartTime_V1R0M0_CalcStartTime.main', '11.1').
2011-04-08 08:43:25.255544 4396 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'TLR_RQ.CalcStartTime.CalcStartTime'.
2011-04-08 08:43:25.264316 1492 UserTrace BIP4413I: Storing unknown message persistently for subsequent processing.
The message has been stored persistently by the AggregateReply node. If it is subsequently discovered to be a valid reply in an aggregation then it will be processed as such at that time. If a number of seconds passes as specified by the 'unknown timeout' attribute, then the message will be propagated to the 'unknown' terminal.
No user action required.

Then later when the response comes in the flow can't find the original and ceases to execute the flow.

2011-04-08 08:43:27.630090 4920 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'TLR_AGG_RS.IAB.TLR.AGG.RS.IN' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-04-08 08:43:27.630266 4920 UserTrace BIP6061I: Parser type ''BLOB'' created on behalf of node 'TLR_AGG_RS.IAB.TLR.AGG.RS.IN' to handle portion of incoming message of length '4374' bytes beginning at offset '364'. Parser type selected based on value ''NONE'' from previous parser.
2011-04-08 08:43:27.638023 4920 UserTrace BIP4412I: Corresponding request record not found for the reply message.
An AggregateReply node has received a message at its 'in' terminal. No corresponding record of a request message being sent could be found. See subsequent messages to determine how this situation has been handled.
It is possible that extraneous messages are arriving at the AggregateReply node 'in' terminal. Check your flow to ensure that the only messages arriving here are replies to request messages previously sent out and passed through an AggregateRequest node. It is possible that this message is a valid reply but part of an aggregation which previously timed out. It is possible that this is a reply to a message which has not yet been recorded by an AggregateRequest node. This can happen if request messages are sent outside of transactional control. Adjust your transaction settings to ensure that messages are sent under transactional control.
2011-04-08 08:43:27.647132 4920 UserTrace BIP4413I: Storing unknown message persistently for subsequent processing.
The message has been stored persistently by the AggregateReply node. If it is subsequently discovered to be a valid reply in an aggregation then it will be processed as such at that time. If a number of seconds passes as specified by the 'unknown timeout' attribute, then the message will be propagated to the 'unknown' terminal.
No user action required.
2011-04-08 08:43:31.614786 5716 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'TLR_AGG_RS.processMonetary' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-04-08 08:43:31.615892 5716 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'TLR_AGG_RS.processMonetary' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-04-08 08:43:31.616142 5716 UserTrace BIP6061I: Parser type ''BLOB'' created on behalf of node 'TLR_AGG_RS.processMonetary' to handle portion of incoming message of length '3926' bytes beginning at offset '364'. Parser type selected based on value ''NONE'' from previous parser.
2011-04-08 08:43:36.549266 5716 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'TLR_AGG_RS.processMonetary' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-04-08 08:43:36.549533 5716 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'TLR_AGG_RS.processMonetary' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-04-08 08:43:36.550010 5716 UserTrace BIP6061I: Parser type ''BLOB'' created on behalf of node 'TLR_AGG_RS.processMonetary' to handle portion of incoming message of length '4374' bytes beginning at offset '364'. Parser type selected based on value ''NONE'' from previous parser.
2011-04-08 08:44:03.028563 2888 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'ConfigurationMessageFlow.InputNode'.
2011-04-08 08:44:03.028896 2888 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'ConfigurationMessageFlow.InputNode' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-04-08 08:44:03.029011 2888 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'ConfigurationMessageFlow.InputNode' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-04-08 08:44:03.029242 2888 UserTrace BIP6061I: Parser type ''XMLS'' created on behalf of node 'ConfigurationMessageFlow.InputNode' to handle portion of incoming message of length '348' bytes beginning at offset '364'. Parser type selected based on value ''XMLS'' from previous parser.

Here is the AggregateResponse Module

CREATE COMPUTE MODULE "TLR_AGG_RS_ComputeAggResponse"
CREATE FUNCTION Main() RETURNS BOOLEAN BEGIN

DECLARE I INTEGER 1;
DECLARE J INTEGER;
SET J = CARDINALITY(InputRoot.*[]);
WHILE I < J DO
SET OutputRoot.*[I] = InputRoot.*[I];
SET I = I + 1;
END WHILE;

SET OutputRoot.Properties.MessageDomain = 'XML';
SET OutputRoot.Properties.MessageFormat = 'XML';
-- Set MQMD Variables
SET OutputRoot.MQMD = InputRoot.ComIbmAggregateReplyBody.Teller.MQMD;

/* Copy the TellerProcessMonetary XML to the output */
SET OutputRoot.XML = InputRoot.ComIbmAggregateReplyBody.Teller.XML;
----------------------------------------------------------------
DECLARE ref_MsgHdrRq REFERENCE TO InputRoot.ComIbmAggregateReplyBody.OrigRequest.XML."cfg-env:Envelope"."cfg-env:Header"."cfg-hdr:MessageHeader";
DECLARE ref_MsgHdrRs REFERENCE TO OutputRoot.XML."cfg-env:Envelope"."cfg-env:Header"."cfg-hdr:MessageHeader";
DECLARE ref_TellerRq REFERENCE TO InputRoot.ComIbmAggregateReplyBody.OrigRequest.XML."cfg-env:Envelope"."cfg-env:Body"."CFX".TellerRq;
DECLARE ref_TellerRs REFERENCE TO OutputRoot.XML."cfg-env:Envelope"."cfg-env:Body"."CFX".ProcessMonetaryRs;
DECLARE numReq INTEGER;

SET numReq = CAST(InputRoot.ComIbmAggregateReplyBody.OrigRequest.XML."cfg-env:Envelope"."cfg-env:Header"."cfg-hdr:MessageHeader"."cfg-hdr:ControlOptions"."cfg-hdr:TellerControl"."cfg-hdr:SeqNumber" AS INTEGER);

IF numReq = -1 THEN
SET ref_MsgHdrRs."cfg-hdr:ControlOptions" = NULL;
ELSE
SET ref_MsgHdrRs."cfg-hdr:ControlOptions" =
InputRoot.ComIbmAggregateReplyBody.Teller.XML."cfg-env:Envelope"."cfg-env:Header"."cfg-hdr:MessageHeader"."cfg-hdr:ControlOptions";
END IF;

---------------------------SetUp MQMD details----------------------------------

--Note: we need to ensure the correlid is the msgid from the original request.
SET OutputRoot.MQMD.ReplyToQ = InputRoot.ComIbmAggregateReplyBody.OrigRequest.MQMD.ReplyToQ;
SET OutputRoot.MQMD.ReplyToQMgr = InputRoot.ComIbmAggregateReplyBody.OrigRequest.MQMD.ReplyToQMgr;

SET OutputRoot.MQMD.CorrelId = InputRoot.ComIbmAggregateReplyBody.OrigRequest.MQMD.MsgId;
--Delete the CorrelID from the MessageHeader
SET OutputRoot.XML."cfg-env:Envelope"."cfg-env:Header"."cfg-hdr:MessageHeader"."cfg-hdr:CorrelId" = Null;
SET OutputRoot.MQMD.Report = MQRO_NEW_MSG_ID;
SET OutputRoot.MQMD.Report = BITOR( OutputRoot.MQMD.Report, MQRO_PASS_CORREL_ID);

SET OutputRoot.MQMD.MsgType = MQMT_REPLY;
-- Delete the OrigReplyToQ definition from the response
SET OutputRoot.XML."cfg-env:Envelope"."cfg-env:Header"."cfg-hdr:MessageHeader"."cfg-hdr:From"."cfg-hdr:OrigReplyToQ" = Null;

RETURN TRUE;

END;
END MODULE;

Please give me some details on what to look for in troubleshooting this. Let me know what you'd like to see and I'll post it.

Thanks,
Eric