MQSeries.net :: View topic - Error during parsing BITSTREAM to MRM

MQSeries.net

Tech Exchange

Education

Certifications

Library

Info Center

SupportPacs

FAQÂ Â

Usergroups

RSS Feed - WebSphere MQ Support

RSS Feed - Message Broker Support

MQSeries.net Forum Index » WebSphere Message Broker (ACE) Support » Error during parsing BITSTREAM to MRM

Goto page 1, 2 Next

Error during parsing BITSTREAM to MRM

« View previous topic :: View next topic »

Author

Message

llaros

Posted: Tue Oct 28, 2008 5:26 pm Post subject: Error during parsing BITSTREAM to MRM

Apprentice

Joined: 22 Jan 2008
Posts: 37

Hi

I tried to test a simple scenario (on Broker 6.0.0.2) which is quite well described it the docs. In this scenario part of a message tree is copied from InputRoot to OutputRoot through BLOB. I hadn't problems when copying whole MRM tree.

I have a xml message structured like this

<?xml version="1.0" encoding="ASCII"?>
<getOperationList xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:a="http://www.a.b/operations/a" xsi:type="a:GetOperationList">
<header>
<referenceId>
<value>111</value>
</referenceId>
<relatedSession>
<value>432</value>
</relatedSession>
<relatedProduct>
<value>4324</value>
</relatedProduct>
<relatedProductOwner>
<value>432432</value>
</relatedProductOwner>
<postingApplicationId>
<value>SBI</value>
</postingApplicationId>
</header>
<selector>
<referenceId>
<value>123456</value>
</referenceId>
</selector>
</getOperationList>

where elemets are defined by following types in Message Set called MyMSET
- getOperationList type is: GetOperationList namespace http://www.a.b/operations/a
- header type is: OperationHeader namespace http://www.a.b/operations/b
- relatedSession type is: RelatedSession namespace http://www.a.b/operations/c

Of course all elements are defined in Message Set.

My Code:

Code:

CALL CopyMessageHeaders();

DECLARE parseOptions INTEGER BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError);

DECLARE headerBitStream BLOB;

SET headerBitStream =
CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession
   OPTIONS parseOptions
   SET 'MyMSET'
   TYPE 'getOperationList/header/relatedSession'
   FORMAT 'XML1') AS BLOB);

-- I decoded this variable and the values was <relatedSession><value>432</value></relatedSession>
-- so this should be ok


SET OutputRoot.MRM.header.referenceId.value = '32112345643';

IF headerBitStream IS NOT NULL THEN
CREATE LASTCHILD OF OutputRoot.MRM.header
PARSE ( headerBitStream
OPTIONS parseOptions
SET 'MyMSET
               TYPE 'getOperationList/header/relatedSession'
FORMAT 'XML1');

END IF;

SET OutputRoot.MRM.header.postingApplicationId.value = 'SBI';

I got the exception:

FI Handler Error: The Message ID that was received from the
worker was not the same as the ID Previously specified.: relatedSession, getOperationList

Part of the trace:

Code:

2008-10-29 02:07:23.219026 3532 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'MyMSET' TYPE 'getOperationList/header/relatedSession' FORMAT 'XML1' OPTIONS parseOptions)'' at ('.readDB_Compute.Main', '27.15'). The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-10-29 02:07:23.219066 3532 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'MyMSET' TYPE 'getOperationList/header/relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB)'' at ('.readDB_Compute.Main', '27.10'). This resolved to ''CAST(X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e' AS BLOB)''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-10-29 02:07:23.219110 3532 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = '32112345643';'' at ('.readDB_Compute.Main', '34.9').
2008-10-29 02:07:23.219570 3532 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''32112345643''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-10-29 02:07:23.219587 3532 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''IF headerBitStream IS NOT NULL THEN... END IF;'' at ('.readDB_Compute.Main', '36.9').
2008-10-29 02:07:23.219608 3532 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''headerBitStream'' at ('.readDB_Compute.Main', '36.12'). This resolved to ''headerBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-10-29 02:07:23.219621 3532 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''headerBitStream IS NOT NULL'' at ('.readDB_Compute.Main', '36.28'). The result was ''TRUE''.
2008-10-29 02:07:23.219650 3532 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CREATE LASTCHILD OF OutputRoot.MRM.header PARSE(headerBitStream, 'MyMSET', 'getOperationList/header/relatedSession', 'XML1');'' at ('.readDB_Compute.Main', '37.4').
2008-10-29 02:07:23.219753 3532 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''headerBitStream'' at ('.readDB_Compute.Main', '38.23'). This resolved to ''headerBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-10-29 02:07:23.219768 3532 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '39.34'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-10-29 02:07:23.221380 3532 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.postingApplicationId.value = 'SBI';'' at ('.readDB_Compute.Main', '46.9').
2008-10-29 02:07:23.221403 3532 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''SBI''' to field / variable ''OutputRoot.MRM.header.postingApplicationId.value''.
2008-10-29 02:07:23.221607 3532 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute.Main', '49.3').
2008-10-29 02:07:23.221675 3532 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute'.
2008-10-29 02:07:23.227010 3532 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute1.Main', '2.2').
2008-10-29 02:07:23.227048 3532 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''SET OutputRoot = InputRoot;'' at ('.readDB_Compute1.Main', '3.3').
2008-10-29 02:07:23.227088 3532 UserTrace BIP2539I: Node 'readDB.Compute1': Evaluating expression ''InputRoot'' at ('.readDB_Compute1.Main', '3.20'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-10-29 02:07:23.227102 3532 UserTrace BIP2568I: Node 'readDB.Compute1': Copying sub-tree from ''InputRoot'' to ''OutputRoot''.
2008-10-29 02:07:23.228473 3532 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = 'JDOverride';'' at ('.readDB_Compute1.Main', '4.3').
2008-10-29 02:07:23.228504 3532 UserTrace BIP2566I: Node 'readDB.Compute1': Assigning value '''JDOverride''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-10-29 02:07:23.228521 3532 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute1.Main', '5.3').
2008-10-29 02:07:23.228570 3532 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute1'.
2008-10-29 02:07:23.232336 3532 UserTrace BIP2231E: Error detected whilst processing a message in node 'readDB.inAndErrHandle_v2.MQInput'.
The message broker detected an error whilst processing a message in node 'readDB.inAndErrHandle_v2.MQInput'. The message has been augmented with an exception list and has been propagated to the node's failure terminal for further processing.
See the following messages for details of the error.
2008-10-29 02:07:23.232360 3532 RecoverableException BIP2230E: Error detected whilst processing a message in node 'readDB.MQOutput'.
The message broker detected an error whilst processing a message in node 'readDB.MQOutput'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2008-10-29 02:07:23.232370 3532 ParserException BIP5286E: Message Translation Interface Writing Errors have occurred:
Message Set Name : ''MyMSET''
Message Set Level : '1'
Message Format : ''XML1''
Message Type Path : ''getOperationList''
Review further error messages for an indication to the cause of the errors.
2008-10-29 02:07:23.232395 3532 ParserException BIP5285E: Message Translation Interface Parsing Errors have occurred:
Message Set Name : ''MyMSET''
Message Set Level : '1'
Message Format : ''XML1''
Message Type Path : ''getOperationList/header/relatedSession''
Review further error messages for an indication to the cause of the errors.
2008-10-29 02:07:23.232404 3532 ParserException BIP5337E: An exception has been detected while parsing.
The message identifier in the bitstream (''relatedSession'') differs from the expected message identifier (''getOperationList'').
The body of the input message contains a message identifier (e.g the outermost tag of an XML message). The message identifier has also been specified in a header (e.g. RFH2) or in the properties of an input node. The two identifiers do not match. Fix the problem and resend the message.

What have I missed?

P.S. I tried to use namespaces when indicating type but it didn't work eighter

Thanks for replies in advance.

llaros

Posted: Fri Oct 31, 2008 1:05 am Post subject:

Apprentice

Joined: 22 Jan 2008
Posts: 37

Hi
I have read this page http://publib.boulder.ibm.com/infocenter/wmbhelp/v6r0m0/index.jsp?topic=/com.ibm.etools.mft.doc/ac20701_.htm from docs many times. I have been trying to do similar example and I think that this is not working. Maybe it is due to different message set? In my message set elements are ordered as xsd:sequence and nobody had tested it with such message set.

Have anybody done this before? As I said if I use RootBitStream and copy whole MRM everything works fine.

Should I raise a PMR?

fjb_saper

Posted: Fri Oct 31, 2008 2:57 am Post subject:

Grand High Poobah

Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY

Don't know about raising a PMR but this seems to be a very expensive way of copying part of the bitstream/tree.

If this is between 2 nodes in the flow I would suggest that you park that part of your tree in Environment.Data.yourpath and retrieve back from there. Don't forget to set your parser on the attach node in the environment tree.

Also if you have a namespace issue you might want to restore the bitstream to an Environment variable and reset the namespace on each level before copying back to the Output tree.
Don't forget to set your parser on the attach node in the environment tree.

Have fun

_________________
MQ & Broker admin

llaros

Posted: Fri Oct 31, 2008 5:07 am Post subject:

Apprentice

Joined: 22 Jan 2008
Posts: 37

Thanks for your reply.

1. Maybe this is expensive way of copy, but this is just part of the issue in which I will store part of the message as a BLOB in a database and use it in another flow. I need functionality not a performance but to be honest it is very confusing, that code from the documentation does not work or there is no explanation how to make it work.

2. I have tried to parse the BLOB to the Enviroment as in the example here:
http://publib.boulder.ibm.com/infocenter/wmbhelp/v6r0m0/index.jsp?topic=/com.ibm.etools.mft.doc/ac20701_.htm

Code:

DECLARE bodyBlob BLOB ASBITSTREAM(InputRoot.XMLNS, InputProperties.Encoding,
InputProperties.CodedCharSetId);
CREATE FIELD Environment.Variables.myXMLTree;
DECLARE creationPtr REFERENCE TO Environment.Variables.myXMLTree;
CREATE FIRSTCHILD OF creationPtr DOMAIN('XMLNS') PARSE(bodyBlob,
InputProperties.Encoding,
InputProperties.CodedCharSetId);

I modified the code to fit my case it that way:

Code:

CREATE FIELD Environment.Variables.myXMLTree;
   DECLARE creationPtr REFERENCE TO Environment.Variables.myXMLTree;
   CREATE FIRSTCHILD OF creationPtr DOMAIN('MRM')
      PARSE ( subBitStream
OPTIONS parseOptions
SET 'REBV2'
               TYPE 'getOperationList/header/relatedProductOwner'
               -- TYPE 'relatedProductOwner'
FORMAT 'XML1');

And in the next compute:

Code:

DECLARE ptr REFERENCE TO Environment.Variables.myXMLTree;
SET OutputRoot.MRM.header = ptr;

If I am in the debugging the flow this works, but if I exit debug I got exception:
MtiImbParser Internal Error: endMessageContent messageName does not match current element

Any suggestions?

fjb_saper

Posted: Fri Oct 31, 2008 11:41 am Post subject:

Grand High Poobah

Joined: 18 Nov 2003
Posts: 20756
Location: LI,NY

Take the validation off.

What this is telling you is that you have the validation option set. However in your message set you are appending / creating something that does not conform to the current message set or the messageset the parent is supposed to be in. Hence the error? If you had the full error tree you could go chase the field in question. It could simply be that there is a namespace difference between your source and target....

Enjoy

_________________
MQ & Broker admin

kimbert

Posted: Fri Oct 31, 2008 2:21 pm Post subject:

Jedi Council

Joined: 29 Jul 2003
Posts: 5542
Location: Southampton

Hi llaros,

fjb_saper's suggestion re: validation is not correct, although it wasn't a bad guess. The error is an internal error, and should never happen. Please raise a PMR for this.

You are using the path syntax in the message type field. That syntax is for multipart message scenarios only. Have you defined 'relatedSession' as a message ( i.e. does it appear under the 'Messages' branch of the Outline view)? If not, that should be your next step.

llaros

Posted: Wed Nov 12, 2008 7:03 am Post subject:

Apprentice

Joined: 22 Jan 2008
Posts: 37

Kimber thanks for your reply!
Sorry for the dely - I was out of office!

You were right that the relatedSession element was not defined as a message. I've added new message to my message set defined with type same as a relatedSession element but I have still the same error:

[code:1:4f1aba00e7]
Timestamps are formatted in local time, 60 minutes past GMT.
Trace written by version ; formatter version 6003

2008-11-12 15:33:31.624952 3284 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'readDB.inAndErrHandle_v2.MQInput'.
2008-11-12 15:33:31.626123 3284 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2008-11-12 15:33:31.626138 3284 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2008-11-12 15:33:31.626150 3284 UserTrace BIP6061I: Parser type ''MQRFH2'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '128' bytes beginning at offset '364'. Parser type selected based on value ''MQHRF2'' from previous parser.
2008-11-12 15:33:31.626159 3284 UserTrace BIP6061I: Parser type ''MRM'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '718' bytes beginning at offset '492'. Parser type selected based on value ''MRM'' from previous parser.
2008-11-12 15:33:31.850435 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute.Main', '2.2').
2008-11-12 15:33:31.850538 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CopyMessageHeaders();'' at ('.readDB_Compute.Main', '4.3').
2008-11-12 15:33:31.850585 3284 UserTrace BIP2538I: Node 'readDB.Compute': Evaluating expression ''CopyMessageHeaders()'' at ('.readDB_Compute.Main', '4.8').
2008-11-12 15:33:31.850696 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute.CopyMessageHeaders', '1.40').
2008-11-12 15:33:31.850719 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE I INTEGER 1;'' at ('.readDB_Compute.CopyMessageHeaders', '2.3').
2008-11-12 15:33:31.850738 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE J INTEGER CARDINALITY(InputRoot.*:*[ ]);'' at ('.readDB_Compute.CopyMessageHeaders', '3.3').
2008-11-12 15:33:31.875881 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[ ]'' at ('.readDB_Compute.CopyMessageHeaders', '3.33'). This resolved to ''InputRoot.*:*[]''. The result was ''LIST... First Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-12 15:33:31.875989 3284 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''CARDINALITY(InputRoot.*:*[ ])'' at ('.readDB_Compute.CopyMessageHeaders', '3.21'). The result was ''4''.
2008-11-12 15:33:31.876010 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''WHILE I < J DO ... END WHILE;'' at ('.readDB_Compute.CopyMessageHeaders', '4.3').
2008-11-12 15:33:31.876380 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''1''.
2008-11-12 15:33:31.876401 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-12 15:33:31.876468 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''1 < 4''. The result was ''TRUE''.
2008-11-12 15:33:31.876533 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-12 15:33:31.876552 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''1''.
2008-11-12 15:33:31.876573 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''1''.
2008-11-12 15:33:31.876585 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[1]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-12 15:33:31.876600 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''1''.
2008-11-12 15:33:31.878168 3284 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-12 15:33:31.878221 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-12 15:33:31.878238 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''1''.
2008-11-12 15:33:31.878885 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''1 + 1''. The result was ''2''.
2008-11-12 15:33:31.878904 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''2''.
2008-11-12 15:33:31.878915 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-12 15:33:31.878929 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''2 < 4''. The result was ''TRUE''.
2008-11-12 15:33:31.878944 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-12 15:33:31.878961 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''2''.
2008-11-12 15:33:31.879306 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''2''.
2008-11-12 15:33:31.879341 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[2]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='MQMD' Value=NULL''.
2008-11-12 15:33:31.880426 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''2''.
2008-11-12 15:33:31.880466 3284 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-12 15:33:31.880493 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-12 15:33:31.880508 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''2''.
2008-11-12 15:33:31.880521 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''2 + 1''. The result was ''3''.
2008-11-12 15:33:31.880535 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''3''.
2008-11-12 15:33:31.880548 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-12 15:33:31.880559 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''3 < 4''. The result was ''TRUE''.
2008-11-12 15:33:31.880575 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-12 15:33:31.881303 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''3''.
2008-11-12 15:33:31.881328 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''3''.
2008-11-12 15:33:31.881341 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[3]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='MQRFH2' Value=''''.
2008-11-12 15:33:31.881355 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''3''.
2008-11-12 15:33:31.881423 3284 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-12 15:33:31.881444 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-12 15:33:31.881458 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''3''.
2008-11-12 15:33:31.881473 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''3 + 1''. The result was ''4''.
2008-11-12 15:33:31.881492 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''4''.
2008-11-12 15:33:31.881505 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-12 15:33:31.881523 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''4 < 4''. The result was ''FALSE''.
2008-11-12 15:33:31.881547 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE parseOptions INTEGER BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError);'' at ('.readDB_Compute.Main', '6.3').
2008-11-12 15:33:31.891834 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''FolderBitStream'' at ('.readDB_Compute.Main', '6.38'). This resolved to ''FolderBitStream''. The result was ''4294967296''.
2008-11-12 15:33:31.891883 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateContent'' at ('.readDB_Compute.Main', '6.55'). This resolved to ''ValidateContent''. The result was ''4096''.
2008-11-12 15:33:31.891901 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateValue'' at ('.readDB_Compute.Main', '6.72'). This resolved to ''ValidateValue''. The result was ''8192''.
2008-11-12 15:33:31.891914 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateLocalError'' at ('.readDB_Compute.Main', '6.87'). This resolved to ''ValidateLocalError''. The result was ''1024''.
2008-11-12 15:33:31.891965 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError)'' at ('.readDB_Compute.Main', '6.32'). This resolved to ''BITOR(4294967296, 4096, 8192, 1024)''. The result was ''4294980608''.
2008-11-12 15:33:31.892635 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE subBitStream BLOB CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'getOperationList/header/relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB);'' at ('.readDB_Compute.Main', '10.3').
2008-11-12 15:33:31.895744 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '11.15'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-11-12 15:33:31.899917 3284 UserTrace BIP5493W: Message, element or attribute 'relatedSession' is self-defining within parent ''.
The message, element or attribute 'relatedSession' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-12 15:33:31.900077 3284 UserTrace BIP5493W: Message, element or attribute 'value' is self-defining within parent 'relatedSession'.
The message, element or attribute 'value' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-12 15:33:31.914110 3284 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'getOperationList/header/relatedSession' FORMAT 'XML1' OPTIONS parseOptions)'' at ('.readDB_Compute.Main', '10.35'). The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-12 15:33:31.916261 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'getOperationList/header/relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB)'' at ('.readDB_Compute.Main', '10.29'). This resolved to ''CAST(X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e' AS BLOB)''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-12 15:33:31.916311 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = 'val11';'' at ('.readDB_Compute.Main', '17.3').
2008-11-12 15:33:31.916328 3284 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''val11''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-11-12 15:33:31.916339 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''IF subBitStream IS NOT NULL THEN... END IF;'' at ('.readDB_Compute.Main', '21.9').
2008-11-12 15:33:31.916357 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''subBitStream'' at ('.readDB_Compute.Main', '21.12'). This resolved to ''subBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-12 15:33:31.916362 3284 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''subBitStream IS NOT NULL'' at ('.readDB_Compute.Main', '21.25'). The result was ''TRUE''.
2008-11-12 15:33:31.917467 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CREATE LASTCHILD OF OutputRoot.MRM.header PARSE(subBitStream, 'REBV2', 'getOperationList/header/relatedSession', 'XML1');'' at ('.readDB_Compute.Main', '22.4').
2008-11-12 15:33:31.918199 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''subBitStream'' at ('.readDB_Compute.Main', '23.23'). This resolved to ''subBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-12 15:33:31.918256 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '24.34'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-11-12 15:33:31.921939 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = UCASE(OutputRoot.MRM.header.referenceId.value);'' at ('.readDB_Compute.Main', '32.3').
2008-11-12 15:33:31.921991 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''OutputRoot.MRM.header.referenceId.value'' at ('.readDB_Compute.Main', '32.55'). This resolved to ''OutputRoot.MRM.header.referenceId.value''. The result was '''val11'''.
2008-11-12 15:33:31.922008 3284 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''UCASE(OutputRoot.MRM.header.referenceId.value)'' at ('.readDB_Compute.Main', '32.49'). This resolved to ''UCASE('val11')''. The result was '''VAL11'''.
2008-11-12 15:33:31.922407 3284 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''VAL11''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-11-12 15:33:31.922433 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.LSMApplicationId.value = 'val13';'' at ('.readDB_Compute.Main', '36.9').
2008-11-12 15:33:31.923095 3284 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''val13''' to field / variable ''OutputRoot.MRM.header.LSMApplicationId.value''.
2008-11-12 15:33:31.923719 3284 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute.Main', '38.9').
2008-11-12 15:33:31.923881 3284 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute'.
2008-11-12 15:33:31.923995 3284 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute1.Main', '2.2').
2008-11-12 15:33:31.924013 3284 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''SET OutputRoot = InputRoot;'' at ('.readDB_Compute1.Main', '5.3').
2008-11-12 15:33:31.924030 3284 UserTrace BIP2539I: Node 'readDB.Compute1': Evaluating expression ''InputRoot'' at ('.readDB_Compute1.Main', '5.20'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-11-12 15:33:31.924043 3284 UserTrace BIP2568I: Node 'readDB.Compute1': Copying sub-tree from ''InputRoot'' to ''OutputRoot''.
2008-11-12 15:33:31.930295 3284 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute1.Main', '6.3').
2008-11-12 15:33:31.931100 3284 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute1'.
2008-11-12 15:33:31.947519 3284 UserTrace BIP2231E: Error detected whilst processing a message in node 'readDB.inAndErrHandle_v2.MQInput'.
The message broker detected an error whilst processing a message in node 'readDB.inAndErrHandle_v2.MQInput'. The message has been augmented with an exception list and has been propagated to the node's failure terminal for further processing.
See the following messages for details of the error.
2008-11-12 15:33:31.947565 3284 RecoverableException BIP2230E: Error detected whilst processing a message in node 'readDB.MQOutput'.
The message broker detected an error whilst processing a message in node 'readDB.MQOutput'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2008-11-12 15:33:31.947580 3284 ParserException BIP5286E: Message Translation Interface Writing Errors have occurred:
Message Set Name : ''REBV2''
Message Set Level : '1'
Message Format : ''XML1''
Message Type Path : ''getOperationList''
Review further error messages for an indication to the cause of the errors.
2008-11-12 15:33:31.947593 3284 ParserException BIP5285E: Message Translation Interface Parsing Errors have occurred:
Message Set Name : ''REBV2''
Message Set Level : '1'
Message Format : ''XML1''
Message Type Path : ''getOperationList/header/relatedSession''
Review further error messages for an indication to the cause of the errors.
2008-11-12 15:33:31.947601 3284 ParserException BIP5337E: An exception has been detected while parsing.
The message identifier in the bitstream (''relatedSession'') differs from the expected message identifier (''getOperationList'').
The body of the input message contains a message identifier (e.g the outermost tag of an XML message). The message identifier has also been specified in a header (e.g. RFH2) or in the properties of an input node. The two identifiers do not match. Fix the problem and resend the message.
2008-11-12 15:33:31.949401 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''BEGIN ... END;'' at ('commons.printError_v2.Main', '2.2').
2008-11-12 15:33:31.950160 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE msgNum INTEGER;'' at ('commons.printError_v2.Main', '3.3').
2008-11-12 15:33:31.950683 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE msgTxt CHARACTER;'' at ('commons.printError_v2.Main', '4.3').
2008-11-12 15:33:31.951593 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE descTxt CHARACTER;'' at ('commons.printError_v2.Main', '5.3').
2008-11-12 15:33:31.951648 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE codeTxt CHARACTER;'' at ('commons.printError_v2.Main', '6.3').
2008-11-12 15:33:31.951730 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''commons.getLastExceptionDetail(InputExceptionList, msgNum, msgTxt, descTxt, codeTxt);'' at ('commons.printError_v2.Main', '8.6').
2008-11-12 15:33:31.951757 3284 UserTrace BIP2538I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''commons.getLastExceptionDetail(InputExceptionList, msgNum, msgTxt, descTxt, codeTxt)'' at ('commons.printError_v2.Main', '8.11').
2008-11-12 15:33:31.951793 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''BEGIN ... END;'' at ('commons.getLastExceptionDetail', '6.4').
2008-11-12 15:33:31.951810 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE ptrException REFERENCE TO InputTree.*:*[1];'' at ('commons.getLastExceptionDetail', '8.9').
2008-11-12 15:33:31.952674 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''WHILE LASTMOVE(ptrException) DO ... END WHILE;'' at ('commons.getLastExceptionDetail', '10.3').
2008-11-12 15:33:31.952697 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-12 15:33:31.952718 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-12 15:33:31.952737 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''2230''.
2008-11-12 15:33:31.952749 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-12 15:33:31.952768 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-12 15:33:31.953542 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''2230''.
2008-11-12 15:33:31.953563 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-12 15:33:31.953582 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''Caught exception and rethrowing'''.
2008-11-12 15:33:31.953599 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-12 15:33:31.953626 3284 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '19.10') : Failed to navigate to path element number '2' because it does not exist.
2008-11-12 15:33:31.953643 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''EMPTY ROW''.
2008-11-12 15:33:31.953670 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''EMPTY ROW = '5'''. The result was ''NULL''.
2008-11-12 15:33:31.953687 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-12 15:33:31.953701 3284 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '22.10') : Failed to navigate to path element number '2' because it does not exist.
2008-11-12 15:33:31.953714 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''EMPTY ROW''.
2008-11-12 15:33:31.953727 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''EMPTY ROW = '5'''. The result was ''NULL''.
2008-11-12 15:33:31.953746 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-12 15:33:31.954717 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-12 15:33:31.954736 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-12 15:33:31.954761 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-12 15:33:31.954778 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''5286''.
2008-11-12 15:33:31.954790 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-12 15:33:31.954828 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-12 15:33:31.955547 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''5286''.
2008-11-12 15:33:31.955585 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-12 15:33:31.955604 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''ImbRecoverableException caught from worker when attempting to write out the bitstream.'''.
2008-11-12 15:33:31.955621 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-12 15:33:31.955665 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5''.
2008-11-12 15:33:31.956304 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5 = '5'''. The result was ''TRUE''.
2008-11-12 15:33:31.956352 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorDesc = ptrException.Insert[1].Text;'' at ('commons.getLastExceptionDetail', '20.14').
2008-11-12 15:33:31.956367 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Text'' at ('commons.getLastExceptionDetail', '20.30'). This resolved to ''ptrException.Insert[1].Text''. The result was '''REBV2'''.
2008-11-12 15:33:31.956380 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-12 15:33:31.956390 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=2''.
2008-11-12 15:33:31.956396 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=2 = '5'''. The result was ''FALSE''.
2008-11-12 15:33:31.956403 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-12 15:33:31.956407 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-12 15:33:31.956409 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-12 15:33:31.956413 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-12 15:33:31.956413 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''5285''.
2008-11-12 15:33:31.956415 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-12 15:33:31.956417 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-12 15:33:31.956417 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''5285''.
2008-11-12 15:33:31.956914 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-12 15:33:31.956958 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''ImbRecoverableException caught from worker->parseNext.'''.
2008-11-12 15:33:31.956975 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-12 15:33:31.956993 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5''.
2008-11-12 15:33:31.957265 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5 = '5'''. The result was ''TRUE''.
2008-11-12 15:33:31.957296 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorDesc = ptrException.Insert[1].Text;'' at ('commons.getLastExceptionDetail', '20.14').
2008-11-12 15:33:31.957319 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Text'' at ('commons.getLastExceptionDetail', '20.30'). This resolved to ''ptrException.Insert[1].Text''. The result was '''REBV2'''.
2008-11-12 15:33:31.957338 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-12 15:33:31.957351 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=2''.
2008-11-12 15:33:31.957361 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=2 = '5'''. The result was ''FALSE''.
2008-11-12 15:33:31.958248 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-12 15:33:31.959022 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-12 15:33:31.959375 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-12 15:33:31.959396 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-12 15:33:31.959413 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''5337''.
2008-11-12 15:33:31.959577 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-12 15:33:31.959756 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-12 15:33:31.960418 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''5337''.
2008-11-12 15:33:31.960462 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-12 15:33:31.960481 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.'''.
2008-11-12 15:33:31.960493 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-12 15:33:31.960512 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5''.
2008-11-12 15:33:31.961181 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5 = '5'''. The result was ''TRUE''.
2008-11-12 15:33:31.961896 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorDesc = ptrException.Insert[1].Text;'' at ('commons.getLastExceptionDetail', '20.14').
2008-11-12 15:33:31.961923 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Text'' at ('commons.getLastExceptionDetail', '20.30'). This resolved to ''ptrException.Insert[1].Text''. The result was '''relatedSession'''.
2008-11-12 15:33:31.961936 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-12 15:33:31.961957 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5''.
2008-11-12 15:33:31.962377 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5 = '5'''. The result was ''TRUE''.
2008-11-12 15:33:31.962434 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorDesc = errorDesc || ', ' || ptrException.Insert[2].Text;'' at ('commons.getLastExceptionDetail', '23.14').
2008-11-12 15:33:31.962491 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''errorDesc'' at ('commons.getLastExceptionDetail', '23.30'). This resolved to ''errorDesc''. The result was '''relatedSession'''.
2008-11-12 15:33:31.963138 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''errorDesc || ', ''' at ('commons.getLastExceptionDetail', '23.40'). This resolved to '''relatedSession' || ', '''. The result was '''relatedSession, '''.
2008-11-12 15:33:31.963188 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Text'' at ('commons.getLastExceptionDetail', '23.51'). This resolved to ''ptrException.Insert[2].Text''. The result was '''getOperationList'''.
2008-11-12 15:33:31.963748 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''errorDesc || ', ' || ptrException.Insert[2].Text'' at ('commons.getLastExceptionDetail', '23.48'). This resolved to '''relatedSession, ' || 'getOperationList'''. The result was '''relatedSession, getOperationList'''.
2008-11-12 15:33:31.963949 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-12 15:33:31.964799 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-12 15:33:31.964817 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-12 15:33:31.964830 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-12 15:33:31.964843 3284 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '12.7') : Failed to navigate to path element number '2' because it does not exist.
2008-11-12 15:33:31.964857 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''NULL''.
2008-11-12 15:33:31.965339 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''FALSE''.
2008-11-12 15:33:31.966016 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-12 15:33:31.966072 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-12 15:33:31.966674 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-12 15:33:31.966674 3284 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '12.7') : Failed to navigate to path element number '2' because it does not exist.
2008-11-12 15:33:31.966674 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''NULL''.
2008-11-12 15:33:31.966833 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''FALSE''.
2008-11-12 15:33:31.967327 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-12 15:33:31.967350 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''FALSE''.
2008-11-12 15:33:31.967390 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET OutputRoot = InputRoot;'' at ('commons.printError_v2.Main', '9.3').
2008-11-12 15:33:31.967424 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''InputRoot'' at ('commons.printError_v2.Main', '9.20'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-11-12 15:33:31.967443 3284 UserTrace BIP2568I: Node 'readDB.inAndErrHandle_v2.printError_v2': Copying sub-tree from ''InputRoot'' to ''OutputRoot''.
2008-11-12 15:33:31.967678 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET OutputRoot.MQRFH2.usr.ERRDESC = msgTxt || ': ' || descTxt;'' at ('commons.printError_v2.Main', '10.6').
2008-11-12 15:33:31.969398 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''msgTxt'' at ('commons.printError_v2.Main', '10.42'). This resolved to ''msgTxt''. The result was '''FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.'''.
2008-11-12 15:33:31.969461 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''msgTxt || ': ''' at ('commons.printError_v2.Main', '10.48'). This resolved to '''FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.' || ': '''. The result was '''FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.: '''.
2008-11-12 15:33:31.970140 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''descTxt'' at ('commons.printError_v2.Main', '10.56'). This resolved to ''descTxt''. The result was '''relatedSession, getOperationList'''.
2008-11-12 15:33:31.970161 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''msgTxt || ': ' || descTxt'' at ('commons.printError_v2.Main', '10.54'). This resolved to '''FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.: ' || 'relatedSession, getOperationList'''. The result was '''FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.: relatedSession, getOperationList'''.
2008-11-12 15:33:31.971933 3284 UserTrace BIP2566I: Node 'readDB.inAndErrHandle_v2.printError_v2': Assigning value ''FI Handler Error: The Message ID that was received from the work... (data of len 149 truncated)'' to field / variable ''OutputRoot.MQRFH2.usr.ERRDESC''.
2008-11-12 15:33:31.971979 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET OutputRoot.MQRFH2.usr.ERRCODE = codeTxt;'' at ('commons.printError_v2.Main', '11.3').
2008-11-12 15:33:31.971994 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''codeTxt'' at ('commons.printError_v2.Main', '11.39'). This resolved to ''codeTxt''. The result was '''1002'''.
2008-11-12 15:33:31.972007 3284 UserTrace BIP2566I: Node 'readDB.inAndErrHandle_v2.printError_v2': Assigning value '''1002''' to field / variable ''OutputRoot.MQRFH2.usr.ERRCODE''.
2008-11-12 15:33:31.972015 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''RETURN TRUE;'' at ('commons.printError_v2.Main', '13.3').
2008-11-12 15:33:31.972023 3284 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.inAndErrHandle_v2.printError_v2'.
2008-11-12 15:33:31.972255 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.Trace': Evaluating expression ''Root.MQRFH2.usr.ERRDESC'' at ('', '1.31'). This resolved to ''Root.MQRFH2.usr.ERRDESC''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='ERRDESC' Value='FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.: relatedSession, getOperationList'''.
2008-11-12 15:33:32.028770 3284 Error BIP3051E: Error message ''Msg was put to ERROR QUEUE: 'FI Handler Error: The Message ID that was received from the worker was not the same as the ID Previously specified.: relatedSession, getOperationList'

'' from trace node 'readDB.inAndErrHandle_v2.Trace'.
The trace node 'readDB.inAndErrHandle_v2.Trace' has output the specified error message.
This is an error message provided by the message flow designer. The user response will be determined by the local environment.
2008-11-12 15:33:32.028823 3284 UserTrace BIP4067I: Message propagated to output terminal for trace node 'readDB.inAndErrHandle_v2.Trace'.
The trace node 'readDB.inAndErrHandle_v2.Trace' has received a message and is propagating it to any nodes connected to its output terminal.
No user action required.
2008-11-12 15:33:32.028881 3284 UserTrace BIP4163I: Message propagated to the first terminal of the FlowOrder node 'readDB.inAndErrHandle_v2.FlowOrder'.
The FlowOrder node has received a message and has propagated it to the output terminal called first. Once the processing of the message down the first terminal has finished, the message will be propagated to the second terminal.
No user action required.
2008-11-12 15:33:32.082302 3284 UserTrace BIP2638I: The MQ output node 'readDB.inAndErrHandle_v2.ERR_QUEUE' attempted to write a message to queue ''TEST1.ERR'' connected to queue manager ''''. The MQCC was '0' and the MQRC was '0'.
2008-11-12 15:33:32.082469 3284 UserTrace BIP2622I: Message successfully output by output node 'readDB.inAndErrHandle_v2.ERR_QUEUE' to queue ''TEST1.ERR'' on queue manager ''''.
2008-11-12 15:33:32.082679 3284 UserTrace BIP4164I: Message propagated to the second terminal of the FlowOrder node 'readDB.inAndErrHandle_v2.FlowOrder'.
The FlowOrder node has finished processing a message down the first terminal and has propagated it to the second terminal.
No user action required.
2008-11-12 15:33:32.085952 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''BEGIN ... END;'' at ('subflows.createBLMAlert.Main', '2.2').
2008-11-12 15:33:32.085994 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''CopyMessageHeaders();'' at ('subflows.createBLMAlert.Main', '3.3').
2008-11-12 15:33:32.086021 3284 UserTrace BIP2538I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Evaluating expression ''CopyMessageHeaders()'' at ('subflows.createBLMAlert.Main', '3.8').
2008-11-12 15:33:32.086055 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''BEGIN ... END;'' at ('subflows.createBLMAlert.CopyMessageHeaders', '1.40').
2008-11-12 15:33:32.086086 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''DECLARE I INTEGER 1;'' at ('subflows.createBLMAlert.CopyMessageHeaders', '2.3').
2008-11-12 15:33:32.086826 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''DECLARE J INTEGER;'' at ('subflows.createBLMAlert.CopyMessageHeaders', '3.3').
2008-11-12 15:33:32.086868 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''SET J = CARDINALITY(InputRoot.*:*[ ]);'' at ('subflows.createBLMAlert.CopyMessageHeaders', '4.3').
2008-11-12 15:33:32.087436 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Evaluating expression ''InputRoot.*:*[ ]'' at ('subflows.createBLMAlert.CopyMessageHeaders', '4.23'). This resolved to ''InputRoot.*:*[]''. The result was ''LIST... First Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-12 15:33:32.087471 3284 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Finished evaluating expression ''CARDINALITY(InputRoot.*:*[ ])'' at ('subflows.createBLMAlert.CopyMessageHeaders', '4.11'). The result was ''4''.
2008-11-12 15:33:32.087497 3284 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Executing statement ''WHILE I < J DO ... END WHILE;'' at ('subflows.createBLMAlert.CopyMessageHeaders', '5.3').
2008-11-12 15:33:32.087528 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Evaluating expression ''I'' at ('subflows.createBLMAlert.CopyMessageHeaders', '5.9'). This resolved to ''I''. The result was ''1''.
2008-11-12 15:33:32.087551 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Evaluating expression ''J'' at ('subflows.createBLMAlert.CopyMessageHeaders', '5.13'). This resolved to ''J''. The result was ''4''.
2008-11-12 15:33:32.087585 3284 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.CreateBLMAlert': Evaluating expression ''I < J'' at ('subflows.createBLMAlert.CopyMessageHeaders', '5.9'). This resolved to ''1 < 4''. The result was ''TRU

mqjeff

Posted: Wed Nov 12, 2008 7:14 am Post subject:

Grand Master

Joined: 25 Jun 2008
Posts: 17447

llaros wrote:

2008-11-12 15:33:31.899917 3284 UserTrace BIP5493W: Message, element or attribute 'relatedSession' is self-defining within parent ''.
The message, element or attribute 'relatedSession' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.

Your data does not match your model.

kimbert

Posted: Wed Nov 12, 2008 8:23 am Post subject:

Jedi Council

Joined: 29 Jul 2003
Posts: 5542
Location: Southampton

I'm not convinced that the BIP5493W is reporting a genuine problem because 'relatedSession' is the root node of the subtree which is being written. I smell a defect there, and it may be related to the main problem.

My next step would be to try this

Code:

DECLARE subBitStream BLOB CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB);'

The path syntax in the TYPE field is really intended for CWF scenarios - it can be used to identify the inner message so that the CWF parser can parse it in full at the first attempt ( instead of putting the inner message into the tree as an unparsed BLOB ).

llaros

Posted: Fri Nov 14, 2008 1:54 am Post subject:

Apprentice

Joined: 22 Jan 2008
Posts: 37

Thanks, thanks kimbert!

That is working now, but I still have validation errors in the trace.

Code:

Timestamps are formatted in local time, 60 minutes past GMT.
Trace written by version ; formatter version 6003

2008-11-14 10:17:01.285496 1484 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'readDB.inAndErrHandle_v2.MQInput'.
2008-11-14 10:17:01.293486 1484 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2008-11-14 10:17:01.293495 1484 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2008-11-14 10:17:01.293501 1484 UserTrace BIP6061I: Parser type ''MQRFH2'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '128' bytes beginning at offset '364'. Parser type selected based on value ''MQHRF2'' from previous parser.
2008-11-14 10:17:01.293506 1484 UserTrace BIP6061I: Parser type ''MRM'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '718' bytes beginning at offset '492'. Parser type selected based on value ''MRM'' from previous parser.
2008-11-14 10:17:01.468397 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute.Main', '2.2').
2008-11-14 10:17:01.469400 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CopyMessageHeaders();'' at ('.readDB_Compute.Main', '4.3').
2008-11-14 10:17:01.469457 1484 UserTrace BIP2538I: Node 'readDB.Compute': Evaluating expression ''CopyMessageHeaders()'' at ('.readDB_Compute.Main', '4.8').
2008-11-14 10:17:01.469513 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute.CopyMessageHeaders', '1.40').
2008-11-14 10:17:01.471644 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE I INTEGER 1;'' at ('.readDB_Compute.CopyMessageHeaders', '2.3').
2008-11-14 10:17:01.471652 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE J INTEGER CARDINALITY(InputRoot.*:*[ ]);'' at ('.readDB_Compute.CopyMessageHeaders', '3.3').
2008-11-14 10:17:01.472375 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[ ]'' at ('.readDB_Compute.CopyMessageHeaders', '3.33'). This resolved to ''InputRoot.*:*[]''. The result was ''LIST... First Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-14 10:17:01.472478 1484 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''CARDINALITY(InputRoot.*:*[ ])'' at ('.readDB_Compute.CopyMessageHeaders', '3.21'). The result was ''4''.
2008-11-14 10:17:01.472520 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''WHILE I < J DO ... END WHILE;'' at ('.readDB_Compute.CopyMessageHeaders', '4.3').
2008-11-14 10:17:01.472573 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''1''.
2008-11-14 10:17:01.472610 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-14 10:17:01.472620 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''1 < 4''. The result was ''TRUE''.
2008-11-14 10:17:01.473505 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-14 10:17:01.473556 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''1''.
2008-11-14 10:17:01.473574 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''1''.
2008-11-14 10:17:01.473587 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[1]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-14 10:17:01.473598 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''1''.
2008-11-14 10:17:01.473605 1484 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-14 10:17:01.473610 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-14 10:17:01.474166 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''1''.
2008-11-14 10:17:01.474316 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''1 + 1''. The result was ''2''.
2008-11-14 10:17:01.474722 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''2''.
2008-11-14 10:17:01.474761 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-14 10:17:01.474799 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''2 < 4''. The result was ''TRUE''.
2008-11-14 10:17:01.475774 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-14 10:17:01.475831 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''2''.
2008-11-14 10:17:01.475888 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''2''.
2008-11-14 10:17:01.475924 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[2]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='MQMD' Value=NULL''.
2008-11-14 10:17:01.478234 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''2''.
2008-11-14 10:17:01.479251 1484 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-14 10:17:01.479321 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-14 10:17:01.479367 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''2''.
2008-11-14 10:17:01.479410 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''2 + 1''. The result was ''3''.
2008-11-14 10:17:01.479449 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''3''.
2008-11-14 10:17:01.479485 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-14 10:17:01.479765 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''3 < 4''. The result was ''TRUE''.
2008-11-14 10:17:01.479817 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-14 10:17:01.479948 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''3''.
2008-11-14 10:17:01.480026 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''3''.
2008-11-14 10:17:01.480065 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[3]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='MQRFH2' Value=''''.
2008-11-14 10:17:01.480108 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''3''.
2008-11-14 10:17:01.480165 1484 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-14 10:17:01.480816 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-14 10:17:01.480869 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''3''.
2008-11-14 10:17:01.480909 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''3 + 1''. The result was ''4''.
2008-11-14 10:17:01.481032 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''4''.
2008-11-14 10:17:01.481071 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-14 10:17:01.481168 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''4 < 4''. The result was ''FALSE''.
2008-11-14 10:17:01.481232 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE parseOptions INTEGER BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError);'' at ('.readDB_Compute.Main', '6.3').
2008-11-14 10:17:01.481343 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''FolderBitStream'' at ('.readDB_Compute.Main', '6.38'). This resolved to ''FolderBitStream''. The result was ''4294967296''.
2008-11-14 10:17:01.481387 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateContent'' at ('.readDB_Compute.Main', '6.55'). This resolved to ''ValidateContent''. The result was ''4096''.
2008-11-14 10:17:01.481428 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateValue'' at ('.readDB_Compute.Main', '6.72'). This resolved to ''ValidateValue''. The result was ''8192''.
2008-11-14 10:17:01.481937 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateLocalError'' at ('.readDB_Compute.Main', '6.87'). This resolved to ''ValidateLocalError''. The result was ''1024''.
2008-11-14 10:17:01.482059 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError)'' at ('.readDB_Compute.Main', '6.32'). This resolved to ''BITOR(4294967296, 4096, 8192, 1024)''. The result was ''4294980608''.
2008-11-14 10:17:01.482110 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE subBitStream BLOB CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB);'' at ('.readDB_Compute.Main', '18.3').
2008-11-14 10:17:01.485039 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '22.16'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-11-14 10:17:01.488919 1484 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions)'' at ('.readDB_Compute.Main', '18.34'). The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-14 10:17:01.489920 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB)'' at ('.readDB_Compute.Main', '18.29'). This resolved to ''CAST(X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e' AS BLOB)''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-14 10:17:01.489990 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = 'val11';'' at ('.readDB_Compute.Main', '25.3').
2008-11-14 10:17:01.490612 1484 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''val11''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-11-14 10:17:01.490666 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''IF subBitStream IS NOT NULL THEN... END IF;'' at ('.readDB_Compute.Main', '29.9').
2008-11-14 10:17:01.490721 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''subBitStream'' at ('.readDB_Compute.Main', '29.12'). This resolved to ''subBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-14 10:17:01.490766 1484 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''subBitStream IS NOT NULL'' at ('.readDB_Compute.Main', '29.25'). The result was ''TRUE''.
2008-11-14 10:17:01.490910 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CREATE LASTCHILD OF OutputRoot.MRM.header PARSE(subBitStream, 'REBV2', 'relatedSession', 'XML1');'' at ('.readDB_Compute.Main', '30.4').
2008-11-14 10:17:01.490975 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''subBitStream'' at ('.readDB_Compute.Main', '31.23'). This resolved to ''subBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-14 10:17:01.491708 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '32.34'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-11-14 10:17:01.493034 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = UCASE(OutputRoot.MRM.header.referenceId.value);'' at ('.readDB_Compute.Main', '40.3').
2008-11-14 10:17:01.493087 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''OutputRoot.MRM.header.referenceId.value'' at ('.readDB_Compute.Main', '40.55'). This resolved to ''OutputRoot.MRM.header.referenceId.value''. The result was '''val11'''.
2008-11-14 10:17:01.493105 1484 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''UCASE(OutputRoot.MRM.header.referenceId.value)'' at ('.readDB_Compute.Main', '40.49'). This resolved to ''UCASE('val11')''. The result was '''VAL11'''.
2008-11-14 10:17:01.493118 1484 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''VAL11''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-11-14 10:17:01.493129 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.LSMApplicationId.value = 'val13';'' at ('.readDB_Compute.Main', '44.9').
2008-11-14 10:17:01.493136 1484 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''val13''' to field / variable ''OutputRoot.MRM.header.LSMApplicationId.value''.
2008-11-14 10:17:01.493142 1484 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute.Main', '46.9').
2008-11-14 10:17:01.493147 1484 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute'.
2008-11-14 10:17:01.493775 1484 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute1.Main', '2.2').
2008-11-14 10:17:01.493831 1484 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''SET OutputRoot = InputRoot;'' at ('.readDB_Compute1.Main', '5.3').
2008-11-14 10:17:01.493883 1484 UserTrace BIP2539I: Node 'readDB.Compute1': Evaluating expression ''InputRoot'' at ('.readDB_Compute1.Main', '5.20'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-11-14 10:17:01.493917 1484 UserTrace BIP2568I: Node 'readDB.Compute1': Copying sub-tree from ''InputRoot'' to ''OutputRoot''.
2008-11-14 10:17:01.494789 1484 UserTrace BIP2537I: Node 'readDB.Compute1': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute1.Main', '6.3').
2008-11-14 10:17:01.494912 1484 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute1'.
2008-11-14 10:17:01.497961 1484 UserTrace BIP5493W: Message, element or attribute 'relatedSession' is self-defining within parent ''.
The message, element or attribute 'relatedSession' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-14 10:17:01.595664 1484 UserTrace BIP5493W: Message, element or attribute 'value' is self-defining within parent 'relatedSession'.
The message, element or attribute 'value' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-14 10:17:01.598173 1484 UserTrace BIP5493W: Message, element or attribute 'relatedSession' is self-defining within parent ''.
The message, element or attribute 'relatedSession' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-14 10:17:01.600455 1484 Warning BIP5371E: Message Validation failure. Invalid member for content validation 'Closed'
Element, 'relatedSession', which is defined as a child of a complex type or group which has a type content of 'Closed', has failed to validate successfully.
This could be because it :
a) has not been defined as a member of its parent complex type or group,
b) has been created out of order in the logical tree, for a composition of 'Ordered Set' or 'Sequence',
c) is a duplicate, which is not allowed for a composition of 'Ordered Set' or 'Unordered Set'.

The parent complex type or group has content validation of 'Closed'. The parent element is '/http://www.esb.raiffeisen.pl:getOperationList/header'.
Modify the message set or messageflow and redeploy to the broker or modify the input message and resubmit to the broker.
2008-11-14 10:17:01.600510 1484 UserTrace BIP5493W: Message, element or attribute 'value' is self-defining within parent 'relatedSession'.
The message, element or attribute 'value' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-14 10:17:01.603330 1484 UserTrace BIP2638I: The MQ output node 'readDB.MQOutput' attempted to write a message to queue ''TEST1.OUT'' connected to queue manager ''''. The MQCC was '0' and the MQRC was '0'.
2008-11-14 10:17:01.603621 1484 UserTrace BIP2622I: Message successfully output by output node 'readDB.MQOutput' to queue ''TEST1.OUT'' on queue manager ''''.

Threads encountered in this trace:
1484

Here are some links to my message set.
GetOperationList type:
http://www.flickr.com/photos/llaros/3028759413/sizes/o/

OperationHeader type and relatedSession as a message:
http://www.flickr.com/photos/llaros/3028754929/sizes/o/

header (OperationHeader) is a sequence of complex types.

One question if anyone can answer
Why in the example in documentation the use TYPE 'message/elem1/elem12' not elem12 and why there is nothing about need for elem12 to be defined as a message itself?
http://publib.boulder.ibm.com/infocenter/wmbhelp/v6r0m0/index.jsp?topic=/com.ibm.etools.mft.doc/ad09255_.htm

I really appreciate your hints and answers.

kimbert

Posted: Fri Nov 14, 2008 3:11 am Post subject:

Jedi Council

Joined: 29 Jul 2003
Posts: 5542
Location: Southampton

I would like to try this out, and see what's going on. I can't do that without a better understanding of your message structure. A Trace node should help with that.
Please insert a Trace node with Pattern set to '${Root}' and Destination set to 'User Trace'. Paste the trace node output here.

llaros

Posted: Mon Nov 17, 2008 3:55 am Post subject:

Apprentice

Joined: 22 Jan 2008
Posts: 37

Ok kimbert, here is a trace (I put two trace nodes - first after input second just before output) but this time the message was rolled back to the failure terminal of the MQInput node.

[code:1:54f46259c4]
Timestamps are formatted in local time, 60 minutes past GMT.
Trace written by version ; formatter version 6003

2008-11-17 12:37:09.239813 3892 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'readDB.inAndErrHandle_v2.MQInput'.
2008-11-17 12:37:09.241231 3892 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2008-11-17 12:37:09.241286 3892 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2008-11-17 12:37:09.241321 3892 UserTrace BIP6061I: Parser type ''MQRFH2'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '128' bytes beginning at offset '364'. Parser type selected based on value ''MQHRF2'' from previous parser.
2008-11-17 12:37:09.241349 3892 UserTrace BIP6061I: Parser type ''MRM'' created on behalf of node 'readDB.inAndErrHandle_v2.MQInput' to handle portion of incoming message of length '718' bytes beginning at offset '492'. Parser type selected based on value ''MRM'' from previous parser.
2008-11-17 12:37:09.241370 3892 UserTrace BIP2539I: Node 'readDB.Trace': Evaluating expression ''Root'' at ('', '1.3'). This resolved to ''Root''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-11-17 12:37:09.359495 3892 UserTrace BIP4060I: Data ''(
(0x01000000):Properties = (
(0x03000000):MessageSet = 'REBV2'
(0x03000000):MessageType = 'getOperationList'
(0x03000000):MessageFormat = 'XML1'
(0x03000000):Encoding = 546
(0x03000000):CodedCharSetId = 437
(0x03000000):Transactional = TRUE
(0x03000000):Persistence = FALSE
(0x03000000):CreationTime = GMTTIMESTAMP '2008-11-17 11:33:31.900'
(0x03000000):ExpirationTime = -1
(0x03000000):Priority = 0
(0x03000000):ReplyIdentifier = X'000000000000000000000000000000000000000000000000'
(0x03000000):ReplyProtocol = 'MQ'
(0x03000000):Topic = NULL
(0x03000000):ContentType = ''
)
(0x01000000):MQMD = (
(0x03000000):SourceQueue = 'TEST1.IN'
(0x03000000):Transactional = TRUE
(0x03000000):Encoding = 546
(0x03000000):CodedCharSetId = 437
(0x03000000):Format = 'MQHRF2 '
(0x03000000):Version = 2
(0x03000000):Report = 0
(0x03000000):MsgType = 8
(0x03000000):Expiry = -1
(0x03000000):Feedback = 0
(0x03000000):Priority = 0
(0x03000000):Persistence = 0
(0x03000000):MsgId = X'414d51205742524b365f44454641554c85c01a4920001e0c'
(0x03000000):CorrelId = X'000000000000000000000000000000000000000000000000'
(0x03000000):BackoutCount = 0
(0x03000000):ReplyToQ = ' '
(0x03000000):ReplyToQMgr = 'WBRK6_DEFAULT_QUEUE_MANAGER '
(0x03000000):UserIdentifier = 'MQSIUSER '
(0x03000000):AccountingToken = X'1601051500000092e03c779b0bc11e75b97554f803000000000000000000000b'
(0x03000000):ApplIdentityData = ' '
(0x03000000):PutApplType = 11
(0x03000000):PutApplName = 'C:\Labs\Tools\rfhutil.exe '
(0x03000000):PutDate = DATE '2008-11-17'
(0x03000000):PutTime = GMTTIME '11:33:31.900'
(0x03000000):ApplOriginData = ' '
(0x03000000):GroupId = X'000000000000000000000000000000000000000000000000'
(0x03000000):MsgSeqNumber = 1
(0x03000000):Offset = 0
(0x03000000):MsgFlags = 0
(0x03000000):OriginalLength = -1
)
(0x01000000):MQRFH2 = (
(0x03000000):Version = 2
(0x03000000):Format = ' '
(0x03000000):Encoding = 546
(0x03000000):CodedCharSetId = 437
(0x03000000):Flags = 0
(0x03000000):NameValueCCSID = 1208
(0x01000000):mcd = (
(0x01000000):Msd = (
(0x02000000): = 'MRM'
)
(0x01000000):Set = (
(0x02000000): = 'REBV2'
)
(0x01000000):Type = (
(0x02000000): = 'getOperationList'
)
(0x01000000):Fmt = (
(0x02000000): = 'XML1'
)
)
)
(0x01000021):MRM = (
(0x0300000D)http://www.w3.org/2001/XMLSchema-instance:type = 'http://www.esb.customer.com/operations/ods:GetOperationList'
(0x01000013):header = (
(0x01000013):referenceId = (
(0x0300000B):value = '111'
)
(0x01000013):relatedSession = (
(0x0300000B):value = '432'
)
(0x01000013):relatedProduct = (
(0x0300000B):value = '4324'
)
(0x01000013):relatedProductOwner = (
(0x0300000B):value = 432432
)
(0x01000013):postingApplicationId = (
(0x0300000B):value = 'SBI'
)
)
(0x01000013):selector = (
(0x01000013):referenceId = (
(0x0300000B):value = '123456'
)
)
)
)
'' from trace node 'readDB.Trace'.
The trace node 'readDB.Trace' has output the specified trace data.
This is an information message provided by the message flow designer. The user response will be determined by the local environment.
2008-11-17 12:37:09.281250 3892 UserTrace BIP4067I: Message propagated to output terminal for trace node 'readDB.Trace'.
The trace node 'readDB.Trace' has received a message and is propagating it to any nodes connected to its output terminal.
No user action required.
2008-11-17 12:37:09.875000 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute.Main', '2.2').
2008-11-17 12:37:09.875000 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CopyMessageHeaders();'' at ('.readDB_Compute.Main', '4.3').
2008-11-17 12:37:09.875000 3892 UserTrace BIP2538I: Node 'readDB.Compute': Evaluating expression ''CopyMessageHeaders()'' at ('.readDB_Compute.Main', '4.8').
2008-11-17 12:37:09.886569 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''BEGIN ... END;'' at ('.readDB_Compute.CopyMessageHeaders', '1.40').
2008-11-17 12:37:09.886625 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE I INTEGER 1;'' at ('.readDB_Compute.CopyMessageHeaders', '2.3').
2008-11-17 12:37:09.886644 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE J INTEGER CARDINALITY(InputRoot.*:*[ ]);'' at ('.readDB_Compute.CopyMessageHeaders', '3.3').
2008-11-17 12:37:09.886657 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[ ]'' at ('.readDB_Compute.CopyMessageHeaders', '3.33'). This resolved to ''InputRoot.*:*[]''. The result was ''LIST... First Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-17 12:37:09.886669 3892 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''CARDINALITY(InputRoot.*:*[ ])'' at ('.readDB_Compute.CopyMessageHeaders', '3.21'). The result was ''4''.
2008-11-17 12:37:09.886676 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''WHILE I < J DO ... END WHILE;'' at ('.readDB_Compute.CopyMessageHeaders', '4.3').
2008-11-17 12:37:09.886684 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''1''.
2008-11-17 12:37:09.886689 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-17 12:37:09.887706 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''1 < 4''. The result was ''TRUE''.
2008-11-17 12:37:09.887758 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-17 12:37:09.887776 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''1''.
2008-11-17 12:37:09.887795 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''1''.
2008-11-17 12:37:09.887805 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[1]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Properties' Value=NULL''.
2008-11-17 12:37:09.888526 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''1''.
2008-11-17 12:37:09.889157 3892 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-17 12:37:09.889215 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-17 12:37:09.889524 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''1''.
2008-11-17 12:37:09.889570 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''1 + 1''. The result was ''2''.
2008-11-17 12:37:09.889584 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''2''.
2008-11-17 12:37:09.889596 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-17 12:37:09.889604 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''2 < 4''. The result was ''TRUE''.
2008-11-17 12:37:09.889612 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-17 12:37:09.889616 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''2''.
2008-11-17 12:37:09.889620 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''2''.
2008-11-17 12:37:09.889623 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[2]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='MQMD' Value=NULL''.
2008-11-17 12:37:09.889627 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''2''.
2008-11-17 12:37:09.889629 3892 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-17 12:37:09.889630 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-17 12:37:09.889631 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''2''.
2008-11-17 12:37:09.889632 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''2 + 1''. The result was ''3''.
2008-11-17 12:37:09.889632 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''3''.
2008-11-17 12:37:09.889633 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-17 12:37:09.889633 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''3 < 4''. The result was ''TRUE''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.*:*[I] = InputRoot.*:*[I];'' at ('.readDB_Compute.CopyMessageHeaders', '5.4').
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''3''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.38'). This resolved to ''I''. The result was ''3''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''InputRoot.*:*[I]'' at ('.readDB_Compute.CopyMessageHeaders', '5.26'). This resolved to ''InputRoot.*:*[3]''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='MQRFH2' Value=''''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '5.21'). This resolved to ''I''. The result was ''3''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2568I: Node 'readDB.Compute': Copying sub-tree from ''InputRoot.*:*[I]'' to ''OutputRoot.*:*[I]''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET I = I + 1;'' at ('.readDB_Compute.CopyMessageHeaders', '6.4').
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '6.12'). This resolved to ''I''. The result was ''3''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I + 1'' at ('.readDB_Compute.CopyMessageHeaders', '6.14'). This resolved to ''3 + 1''. The result was ''4''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''I''. The result was ''4''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''J'' at ('.readDB_Compute.CopyMessageHeaders', '4.13'). This resolved to ''J''. The result was ''4''.
2008-11-17 12:37:09.889634 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''I < J'' at ('.readDB_Compute.CopyMessageHeaders', '4.9'). This resolved to ''4 < 4''. The result was ''FALSE''.
2008-11-17 12:37:09.890475 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE parseOptions INTEGER BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError);'' at ('.readDB_Compute.Main', '6.3').
2008-11-17 12:37:09.890506 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''FolderBitStream'' at ('.readDB_Compute.Main', '6.38'). This resolved to ''FolderBitStream''. The result was ''4294967296''.
2008-11-17 12:37:09.890530 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateContent'' at ('.readDB_Compute.Main', '6.55'). This resolved to ''ValidateContent''. The result was ''4096''.
2008-11-17 12:37:09.890549 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateValue'' at ('.readDB_Compute.Main', '6.72'). This resolved to ''ValidateValue''. The result was ''8192''.
2008-11-17 12:37:09.890563 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''ValidateLocalError'' at ('.readDB_Compute.Main', '6.87'). This resolved to ''ValidateLocalError''. The result was ''1024''.
2008-11-17 12:37:09.890575 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''BITOR(FolderBitStream, ValidateContent, ValidateValue, ValidateLocalError)'' at ('.readDB_Compute.Main', '6.32'). This resolved to ''BITOR(4294967296, 4096, 8192, 1024)''. The result was ''4294980608''.
2008-11-17 12:37:09.890583 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''DECLARE subBitStream BLOB CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB);'' at ('.readDB_Compute.Main', '18.3').
2008-11-17 12:37:09.890589 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '22.16'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-11-17 12:37:10.000007 3892 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions)'' at ('.readDB_Compute.Main', '18.34'). The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-17 12:37:10.000201 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''CAST(ASBITSTREAM(InputRoot.MRM.header.relatedSession SET 'REBV2' TYPE 'relatedSession' FORMAT 'XML1' OPTIONS parseOptions) AS BLOB)'' at ('.readDB_Compute.Main', '18.29'). This resolved to ''CAST(X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e' AS BLOB)''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-17 12:37:10.001493 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = 'val11';'' at ('.readDB_Compute.Main', '25.3').
2008-11-17 12:37:10.001984 3892 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''val11''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-11-17 12:37:10.002020 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''IF subBitStream IS NOT NULL THEN... END IF;'' at ('.readDB_Compute.Main', '29.9').
2008-11-17 12:37:10.002041 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''subBitStream'' at ('.readDB_Compute.Main', '29.12'). This resolved to ''subBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-17 12:37:10.002057 3892 UserTrace BIP2540I: Node 'readDB.Compute': Finished evaluating expression ''subBitStream IS NOT NULL'' at ('.readDB_Compute.Main', '29.25'). The result was ''TRUE''.
2008-11-17 12:37:10.002120 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''CREATE LASTCHILD OF OutputRoot.MRM.header PARSE(subBitStream, 'REBV2', 'relatedSession', 'XML1');'' at ('.readDB_Compute.Main', '30.4').
2008-11-17 12:37:10.002142 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''subBitStream'' at ('.readDB_Compute.Main', '31.23'). This resolved to ''subBitStream''. The result was ''X'3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e'''.
2008-11-17 12:37:10.002166 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''parseOptions'' at ('.readDB_Compute.Main', '32.34'). This resolved to ''parseOptions''. The result was ''4294980608''.
2008-11-17 12:37:10.485018 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.referenceId.value = UCASE(OutputRoot.MRM.header.referenceId.value);'' at ('.readDB_Compute.Main', '40.3').
2008-11-17 12:37:10.485387 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''OutputRoot.MRM.header.referenceId.value'' at ('.readDB_Compute.Main', '40.55'). This resolved to ''OutputRoot.MRM.header.referenceId.value''. The result was '''val11'''.
2008-11-17 12:37:10.485409 3892 UserTrace BIP2539I: Node 'readDB.Compute': Evaluating expression ''UCASE(OutputRoot.MRM.header.referenceId.value)'' at ('.readDB_Compute.Main', '40.49'). This resolved to ''UCASE('val11')''. The result was '''VAL11'''.
2008-11-17 12:37:10.485431 3892 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''VAL11''' to field / variable ''OutputRoot.MRM.header.referenceId.value''.
2008-11-17 12:37:10.485462 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''SET OutputRoot.MRM.header.LSMApplicationId.value = 'val13';'' at ('.readDB_Compute.Main', '44.9').
2008-11-17 12:37:10.485490 3892 UserTrace BIP2566I: Node 'readDB.Compute': Assigning value '''val13''' to field / variable ''OutputRoot.MRM.header.LSMApplicationId.value''.
2008-11-17 12:37:10.486268 3892 UserTrace BIP2537I: Node 'readDB.Compute': Executing statement ''RETURN TRUE;'' at ('.readDB_Compute.Main', '46.9').
2008-11-17 12:37:10.486386 3892 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'readDB.Compute'.
2008-11-17 12:37:10.486447 3892 UserTrace BIP2539I: Node 'readDB.Trace1': Evaluating expression ''Root'' at ('', '1.3'). This resolved to ''Root''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-11-17 12:37:10.489048 3892 UserTrace BIP5493W: Message, element or attribute 'relatedSession' is self-defining within parent ''.
The message, element or attribute 'relatedSession' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-17 12:37:10.490985 3892 UserTrace BIP5493W: Message, element or attribute 'value' is self-defining within parent 'http://www.esb.customer.com/types/common/reb:relatedSession'.
The message, element or attribute 'value' did not match with any corresponding
artifact in the message model hence it is considered to be self-defining.
If it is not intended that this message, element or attribute be self-defining,
check that the message set is referenced in the message properties, or
modify the message model to correspond to the instance message, or
modify the instance message to correspond to the message model.
2008-11-17 12:37:10.495702 3892 Warning BIP5371E: Message Validation failure. Invalid member for content validation 'Closed'
Element, 'value', which is defined as a child of a complex type or group which has a type content of 'Closed', has failed to validate successfully.
This could be because it :
a) has not been defined as a member of its parent complex type or group,
b) has been created out of order in the logical tree, for a composition of 'Ordered Set' or 'Sequence',
c) is a duplicate, which is not allowed for a composition of 'Ordered Set' or 'Unordered Set'.

The parent complex type or group has content validation of 'Closed'. The parent element is '/http://www.esb.customer.com/types/common/reb:relatedSession'.
Modify the message set or messageflow and redeploy to the broker or modify the input message and resubmit to the broker.
2008-11-17 12:37:10.567266 3892 UserTrace BIP4060I: Data ''(
(0x01000000):Properties = (
(0x03000000):MessageSet = 'REBV2'
(0x03000000):MessageType = 'getOperationList'
(0x03000000):MessageFormat = 'XML1'
(0x03000000):Encoding = 546
(0x03000000):CodedCharSetId = 437
(0x03000000):Transactional = TRUE
(0x03000000):Persistence = FALSE
(0x03000000):CreationTime = GMTTIMESTAMP '2008-11-17 11:33:31.900'
(0x03000000):ExpirationTime = -1
(0x03000000):Priority = 0
(0x03000000):ReplyIdentifier = X'000000000000000000000000000000000000000000000000'
(0x03000000):ReplyProtocol = 'MQ'
(0x03000000):Topic = NULL
(0x03000000):ContentType = ''
)
(0x01000000):MQMD = (
(0x03000000):SourceQueue = 'TEST1.IN'
(0x03000000):Transactional = TRUE
(0x03000000):Encoding = 546
(0x03000000):CodedCharSetId = 437
(0x03000000):Format = 'MQHRF2 '
(0x03000000):Version = 2
(0x03000000):Report = 0
(0x03000000):MsgType = 8
(0x03000000):Expiry = -1
(0x03000000):Feedback = 0
(0x03000000):Priority = 0
(0x03000000):Persistence = 0
(0x03000000):MsgId = X'414d51205742524b365f44454641554c85c01a4920001e0c'
(0x03000000):CorrelId = X'000000000000000000000000000000000000000000000000'
(0x03000000):BackoutCount = 0
(0x03000000):ReplyToQ = ' '
(0x03000000):ReplyToQMgr = 'WBRK6_DEFAULT_QUEUE_MANAGER '
(0x03000000):UserIdentifier = 'MQSIUSER '
(0x03000000):AccountingToken = X'1601051500000092e03c779b0bc11e75b97554f803000000000000000000000b'
(0x03000000):ApplIdentityData = ' '
(0x03000000):PutApplType = 11
(0x03000000):PutApplName = 'C:\Labs\Tools\rfhutil.exe '
(0x03000000):PutDate = DATE '2008-11-17'
(0x03000000):PutTime = GMTTIME '11:33:31.900'
(0x03000000):ApplOriginData = ' '
(0x03000000):GroupId = X'000000000000000000000000000000000000000000000000'
(0x03000000):MsgSeqNumber = 1
(0x03000000):Offset = 0
(0x03000000):MsgFlags = 0
(0x03000000):OriginalLength = -1
)
(0x01000000):MQRFH2 = (
(0x03000000):Version = 2
(0x03000000):Format = ' '
(0x03000000):Encoding = 546
(0x03000000):CodedCharSetId = 437
(0x03000000):Flags = 0
(0x03000000):NameValueCCSID = 1208
(0x01000000):mcd = (
(0x01000000):Msd = (
(0x02000000): = 'MRM'
)
(0x01000000):Set = (
(0x02000000): = 'REBV2'
)
(0x01000000):Type = (
(0x02000000): = 'getOperationList'
)
(0x01000000):Fmt = (
(0x02000000): = 'XML1'
)
)
)
(0x01000021):MRM = (
(0x01000000):header = (
(0x01000000):referenceId = (
(0x03000000):value = 'VAL11'
)
(0x0100001B)http://www.esb.customer.com/types/common/reb:relatedSession = (
'' from trace node 'readDB.Trace1'.
The trace node 'readDB.Trace1' has output the specified trace data.
This is an information message provided by the message flow designer. The user response will be determined by the local environment.
2008-11-17 12:37:10.625768 3892 UserTrace BIP2231E: Error detected whilst processing a message in node 'readDB.inAndErrHandle_v2.MQInput'.
The message broker detected an error whilst processing a message in node 'readDB.inAndErrHandle_v2.MQInput'. The message has been augmented with an exception list and has been propagated to the node's failure terminal for further processing.
See the following messages for details of the error.
2008-11-17 12:37:10.625815 3892 RecoverableException BIP2230E: Error detected whilst processing a message in node 'readDB.Trace1'.
The message broker detected an error whilst processing a message in node 'readDB.Trace1'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2008-11-17 12:37:10.625830 3892 ParserException BIP5285E: Message Translation Interface Parsing Errors have occurred:
Message Set Name : ''REBV2''
Message Set Level : '1'
Message Format : ''XML1''
Message Type Path : ''relatedSession''
Review further error messages for an indication to the cause of the errors.
2008-11-17 12:37:10.625843 3892 ParserException BIP5354E: MTI internal error: diagnostic information ''endMessageContent messageName does not match current element''.
An internal software error has occurred in the Message Translation Interface Parser. The diagnostic information associated with this message is: ''endMessageContent messageName does not match current element''.
Shutdown and restart the message broker. If the problem continues to occur, then restart the system. If the problem still continues to occur contact your IBM support center.
2008-11-17 12:37:10.625864 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''BEGIN ... END;'' at ('commons.printError_v2.Main', '2.2').
2008-11-17 12:37:10.625867 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE msgNum INTEGER;'' at ('commons.printError_v2.Main', '3.3').
2008-11-17 12:37:10.625870 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE msgTxt CHARACTER;'' at ('commons.printError_v2.Main', '4.3').
2008-11-17 12:37:10.692175 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE descTxt CHARACTER;'' at ('commons.printError_v2.Main', '5.3').
2008-11-17 12:37:10.692221 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE codeTxt CHARACTER;'' at ('commons.printError_v2.Main', '6.3').
2008-11-17 12:37:10.692237 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''commons.getLastExceptionDetail(InputExceptionList, msgNum, msgTxt, descTxt, codeTxt);'' at ('commons.printError_v2.Main', '8.6').
2008-11-17 12:37:10.692250 3892 UserTrace BIP2538I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''commons.getLastExceptionDetail(InputExceptionList, msgNum, msgTxt, descTxt, codeTxt)'' at ('commons.printError_v2.Main', '8.11').
2008-11-17 12:37:10.692258 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''BEGIN ... END;'' at ('commons.getLastExceptionDetail', '6.4').
2008-11-17 12:37:10.692266 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''DECLARE ptrException REFERENCE TO InputTree.*:*[1];'' at ('commons.getLastExceptionDetail', '8.9').
2008-11-17 12:37:10.692271 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''WHILE LASTMOVE(ptrException) DO ... END WHILE;'' at ('commons.getLastExceptionDetail', '10.3').
2008-11-17 12:37:10.692275 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-17 12:37:10.692277 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-17 12:37:10.692280 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''2230''.
2008-11-17 12:37:10.692281 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-17 12:37:10.692283 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-17 12:37:10.694210 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''2230''.
2008-11-17 12:37:10.694216 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-17 12:37:10.694223 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''Caught exception and rethrowing'''.
2008-11-17 12:37:10.694227 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-17 12:37:10.694231 3892 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '19.10') : Failed to navigate to path element number '2' because it does not exist.
2008-11-17 12:37:10.694232 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''EMPTY ROW''.
2008-11-17 12:37:10.694234 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''EMPTY ROW = '5'''. The result was ''NULL''.
2008-11-17 12:37:10.694236 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-17 12:37:10.694237 3892 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '22.10') : Failed to navigate to path element number '2' because it does not exist.
2008-11-17 12:37:10.694238 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''EMPTY ROW''.
2008-11-17 12:37:10.694238 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''EMPTY ROW = '5'''. The result was ''NULL''.
2008-11-17 12:37:10.694239 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-17 12:37:10.694239 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''5285''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''5285''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''ImbRecoverableException caught from worker->parseNext.'''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5 = '5'''. The result was ''TRUE''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorDesc = ptrException.Insert[1].Text;'' at ('commons.getLastExceptionDetail', '20.14').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Text'' at ('commons.getLastExceptionDetail', '20.30'). This resolved to ''ptrException.Insert[1].Text''. The result was '''REBV2'''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=2''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=2 = '5'''. The result was ''FALSE''.
2008-11-17 12:37:10.694240 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-17 12:37:10.710730 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-17 12:37:10.710777 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-17 12:37:10.710792 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-17 12:37:10.710804 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''5354''.
2008-11-17 12:37:10.710814 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''TRUE''.
2008-11-17 12:37:10.710821 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageNumber = ptrException.Number;'' at ('commons.getLastExceptionDetail', '13.11').
2008-11-17 12:37:10.712470 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '13.31'). This resolved to ''ptrException.Number''. The result was ''5354''.
2008-11-17 12:37:10.712515 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET messageText = ptrException.Text;'' at ('commons.getLastExceptionDetail', '14.11').
2008-11-17 12:37:10.712535 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Text'' at ('commons.getLastExceptionDetail', '14.29'). This resolved to ''ptrException.Text''. The result was '''MtiImbParser Internal Error'''.
2008-11-17 12:37:10.712548 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[1].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '19.7').
2008-11-17 12:37:10.712569 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type'' at ('commons.getLastExceptionDetail', '19.10'). This resolved to ''ptrException.Insert[1].Type''. The result was ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5''.
2008-11-17 12:37:10.712589 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Type = '5''' at ('commons.getLastExceptionDetail', '19.38'). This resolved to ''ROW... Root Element Type=50331648 NameSpace='' Name='Type' Value=5 = '5'''. The result was ''TRUE''.
2008-11-17 12:37:10.769328 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorDesc = ptrException.Insert[1].Text;'' at ('commons.getLastExceptionDetail', '20.14').
2008-11-17 12:37:10.769373 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[1].Text'' at ('commons.getLastExceptionDetail', '20.30'). This resolved to ''ptrException.Insert[1].Text''. The result was '''endMessageContent messageName does not match current element'''.
2008-11-17 12:37:10.769389 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Insert[2].Type = '5' THEN... END IF;'' at ('commons.getLastExceptionDetail', '22.7').
2008-11-17 12:37:10.769399 3892 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '22.10') : Failed to navigate to path element number '2' because it does not exist.
2008-11-17 12:37:10.769409 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type'' at ('commons.getLastExceptionDetail', '22.10'). This resolved to ''ptrException.Insert[2].Type''. The result was ''EMPTY ROW''.
2008-11-17 12:37:10.769415 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Insert[2].Type = '5''' at ('commons.getLastExceptionDetail', '22.38'). This resolved to ''EMPTY ROW = '5'''. The result was ''NULL''.
2008-11-17 12:37:10.769420 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET errorCode = 1002;'' at ('commons.getLastExceptionDetail', '25.12').
2008-11-17 12:37:10.769425 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-17 12:37:10.769428 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-17 12:37:10.769430 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-17 12:37:10.769432 3892 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '12.7') : Failed to navigate to path element number '2' because it does not exist.
2008-11-17 12:37:10.769433 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''NULL''.
2008-11-17 12:37:10.769433 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''FALSE''.
2008-11-17 12:37:10.769434 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-17 12:37:10.769435 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''TRUE''.
2008-11-17 12:37:10.769435 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''IF ptrException.Number IS NOT NULL THEN... END IF;'' at ('commons.getLastExceptionDetail', '12.4').
2008-11-17 12:37:10.769436 3892 UserTrace BIP2543I: Node 'readDB.inAndErrHandle_v2.printError_v2': ('commons.getLastExceptionDetail', '12.7') : Failed to navigate to path element number '2' because it does not exist.
2008-11-17 12:37:10.769436 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''ptrException.Number'' at ('commons.getLastExceptionDetail', '12.7'). This resolved to ''ptrException.Number''. The result was ''NULL''.
2008-11-17 12:37:10.769436 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''ptrException.Number IS NOT NULL'' at ('commons.getLastExceptionDetail', '12.27'). The result was ''FALSE''.
2008-11-17 12:37:10.769436 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''MOVE ptrException LASTCHILD;'' at ('commons.getLastExceptionDetail', '30.4').
2008-11-17 12:37:10.769436 3892 UserTrace BIP2540I: Node 'readDB.inAndErrHandle_v2.printError_v2': Finished evaluating expression ''LASTMOVE(ptrException)'' at ('commons.getLastExceptionDetail', '10.9'). The result was ''FALSE''.
2008-11-17 12:37:10.769436 3892 UserTrace BIP2537I: Node 'readDB.inAndErrHandle_v2.printError_v2': Executing statement ''SET OutputRoot = InputRoot;'' at ('commons.printError_v2.Main', '9.3').
2008-11-17 12:37:10.769437 3892 UserTrace BIP2539I: Node 'readDB.inAndErrHandle_v2.printError_v2': Evaluating expression ''InputRoot'' at ('commons.printError_v2.Main', '9.20'). This resolved to ''InputRoot''. The result was ''ROW... Root Element Type=16777216 NameSpace='' Name='Root' Value=NULL''.
2008-11-17 12:37:10.769437

kimbert

Posted: Mon Nov 17, 2008 5:58 am Post subject:

Jedi Council

Joined: 29 Jul 2003
Posts: 5542
Location: Southampton

Solved! If you look carefully at the user trace, it becomes clear what is going on:

Your input message tree looked like this:

Code:

(0x01000021):MRM = (
(0x0300000D)http://www.w3.org/2001/XMLSchema-instance:type = 'http://www.esb.customer.com/operations/ods:GetOperationList'
(0x01000013):header = (
(0x01000013):referenceId = (
(0x0300000B):value = '111'
)
(0x01000013):relatedSession = (
(0x0300000B):value = '432'
)
(0x01000013):relatedProduct = (
(0x0300000B):value = '4324'
)
(0x01000013):relatedProductOwner = (
(0x0300000B):value = 432432
)
(0x01000013):postingApplicationId = (
(0x0300000B):value = 'SBI'
)
)
(0x01000013):selector = (
(0x01000013):referenceId = (
(0x0300000B):value = '123456'
)
)
)
)

But your output message tree ( after the Compute node ) looks like this:

Code:

(0x01000021):MRM = (
(0x01000000):header = (
(0x01000000):referenceId = (
(0x03000000):value = 'VAL11'
)
(0x0100001B)http://www.esb.customer.com/types/common/reb:relatedSession = (

Note that relatedSession has acquired a namespace. This is why you are getting a validation error.

One possibility is that the FolderBitstream serialization of relatedSession has incorrectly assigned a namespace to the root tag. However, if you decode subBitstream as reported in the user trace, you get this:

Code:

3c72656c6174656453657373696f6e3e3c76616c75653e3433323c2f76616c75653e3c2f72656c6174656453657373696f6e3e
<relatedSession><value>432</value></relatedSession>

which correctly has no namespace.
After discussions with a colleague, I believe that your message definition for relatedSession has a namespace on it. So when you execute this statement:

Code:

CREATE LASTCHILD OF OutputRoot.MRM.header PARSE(subBitStream, 'REBV2', 'relatedSession', 'XML1');

you get a namespace on the root node of the parsed message tree.

Solution: Find the definition of the message 'relatedSession' and remove the namespace.

llaros

Posted: Tue Nov 18, 2008 5:20 am Post subject:

Apprentice

Joined: 22 Jan 2008
Posts: 37

Hi Kimbert.

Again, thanks for your help.

I would like to write that this is working now, but I can't. Maybe it is due to my poor knowledge of Message Editor

.

I opened mxsd file in the Message Editor, then I clicked

on the overview tab in the structure column -> Messages -> relatedSession
then I clicked on the Properties tab.
I went to physical properties -> XML1 -> Message.
Output Namespace Declaration has been set to "As required" (XML declaration section).

(Field identification section) Namespace is grayed and blank.

Next I went to Elements and Attributes (structure column) instead of Messages. I clicked on the properties. I selected Logical properties -> Global Element. Name was set to relatedSession, Type to com.customer.esb.types.common.reb:Session, Namespace is grayed and set to http://www.esb.customer.com/types/common/reb. It is grayed so I cannot change it. I went to Physical properties -> XML1 -> Global Element ant there is just one attribute XML Name which is set to relatedSession.

Any suggestions? Maybe it is not possible to do that with a namespace aware message set?

kimbert

Posted: Tue Nov 18, 2008 5:58 am Post subject:

Jedi Council

Joined: 29 Jul 2003
Posts: 5542
Location: Southampton

hi llaros,

Quote:

Namespace is grayed and set to http://www.esb.customer.com/types/common/reb. It is grayed so I cannot change it.

You were looking in the correct place. This field is grayed out for a good reason - it is a global element, so it automatically inherits the 'target namespace' of the xsd ( or mxsd in this case ). The only way to change its namespace would be to
a) make it a local element, and set 'Element form default' to 'unqualified' on the schema
or
b) create another mxsd file in the noTargetNamespace, add the current mxsd as an imported schema, and create a global element 'relatedSession' in the new schema. You would have to set its complex type to the same as it was in the first schema.

a) is not a solution, because you cannot create an MRM message from a local element
b) is possible, but I don't recommend it. The only reason for making a message 'relatedSession' was as a workaround for the original problem. Now the workaround is starting to look worse than the original problem.

Next step: We need to go back to the original problem, and find out why this error was being reported:

Quote:

2008-10-29 02:07:23.232395 3532 ParserException BIP5285E: Message Translation Interface Parsing Errors have occurred:
Message Set Name : ''MyMSET''
Message Set Level : '1'
Message Format : ''XML1''
Message Type Path : ''getOperationList/header/relatedSession''
Review further error messages for an indication to the cause of the errors.

Apologies for sending you in the wrong direction there. I will try out your scenario on my own machine, and get back to you.

Display posts from previous:

Goto page 1, 2 Next

Page 1 of 2

MQSeries.net Forum Index » WebSphere Message Broker (ACE) Support » Error during parsing BITSTREAM to MRM

Jump to:

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum

Protected by Anti-Spam ACP