| Author |
Message
|
| DaveCanto |
 Posted: Tue Nov 08, 2011 7:33 am Post subject: Touched the boundary of code reusability in WBIMB Toolkit? |
 |
|
Novice
Joined: 01 Feb 2008
Posts: 11
Location: Belgium - EU
|
Hi,
Recently our newly deployed messageflows started acting strange. In debug mode, we always get the following exception when a message passes through a messageflow:
"String '%1' is not of the correct form to cast to bool"
Our messageflows make use of some commonly used subflows for exception handling, archiving and logging which are stored in separate messageflow projects grouped together in our own 'framework' for broker developments.
Once a message goes into such a subflow, this exception is already thrown when touching a compute node in that subflow without executing any logic from that compute node. I was able to see this behaviour in the debug mode.
Our subflows make use of a couple of external variables, promoted and user-defined properties. I have a feeling that above's exception might have something to do with these.
I already tried to build, deploy and test our messageflows in a clean workspace on my own workstation and on another workstation as well.
I get the feeling that something went corrupt somewhere in our subflows, but I cannot find out where and why? Are we touching the boundaries here of code/logic reusability in IBM's Message Broker Toolkit v6.1.0.8?
Your help is much appreciated!
_________________
Do not underestimate the power of ... unit testing and continuous integration. |
|
| Back to top |
|
 |
| fjb_saper |
| Posted: Tue Nov 08, 2011 7:44 am Post subject: |
|
|
Grand High Poobah
Joined: 18 Nov 2003
Posts: 20768
Location: LI,NY
|
Have you tried following on the flows?
Recompile (including sub-flows), rebuild (bar file), redeploy? 
_________________
MQ & Broker admin |
|
| Back to top |
|
|
| mqjeff |
| Posted: Tue Nov 08, 2011 7:51 am Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
Are you using some process during deployment to set or update UDPs and promoted properties on flows? Perhaps this is inserting an incorrect value into a property - like "one" instead of 1 or 'true' instead of true - into a field?
it's clearly a field that is supposed to hold a Boolean value. |
|
| Back to top |
|
|
| vmcgloin |
| Posted: Tue Nov 08, 2011 12:18 pm Post subject: |
|
|
Knight
Joined: 04 Apr 2002
Posts: 560
Location: Scotland
|
Your description implies that you do not know which string is failing to be cast to a boolean. Is this the case? Does the debugger (or system log when not in debug) not show the details? If not I would turn to trace.
Also, I suspect that you are looking too deep into this and your subflows etc are not in themselves the problem - more likely as better minds than mine have pointed out - you just have a configuration problem during deployment. |
|
| Back to top |
|
|
| mqjeff |
| Posted: Tue Nov 08, 2011 12:25 pm Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
| vmcgloin wrote: |
| as better minds than mine have pointed out |
noisier, maybe. |
|
| Back to top |
|
|
| DaveCanto |
| Posted: Wed Nov 09, 2011 7:54 am Post subject: |
|
|
Novice
Joined: 01 Feb 2008
Posts: 11
Location: Belgium - EU
|
Thanks for your quick replies, gents.
| Quote: |
Have you tried following on the flows?
Recompile (including sub-flows), rebuild (bar file), redeploy?
|
Yes, I did several clean operations, rebuilds and redeploys already and even started a new workspace from the toolkit.
| Quote: |
| Are you using some process during deployment to set or update UDPs and promoted properties on flows? Perhaps this is inserting an incorrect value into a property - like "one" instead of 1 or 'true' instead of true - into a field? |
No, we don't use any automated process to create bar-files. Those are created from the developer's toolkits only.
| Quote: |
| Your description implies that you do not know which string is failing to be cast to a boolean. Is this the case? Does the debugger (or system log when not in debug) not show the details? If not I would turn to trace. |
Yes, that's right. Both debugger and usertrace (see below) show the same exception. I have a feeling that the bar-file (after building it) still contains some kind of reference to a promoted property or user-defined property which I've created in the past and removed afterwards.
I'm going to investigate the actual bar-file which is sitting on my harddrive to find out if it has some trace of that previously created external variable somewhere. If you have any kind of tips or tools to help me with my investigation, please feel free to post them here. Thank you.
This is the actual exception which is causing me troubles:
| Code: |
Error casting character string '''''' to boolean.
The character string had the value ''''''. Only the character strings 'TRUE', 'FALSE', and 'UNKNOWN' can be cast to booleans.
Ensure that the character string being cast has one of the above values.
|
You can also see it in today's usertrace:
| Code: |
2011-11-09 10:23:04.889774 3016 UserTrace BIP4040I: The Execution Group ''ACCB'' has processed a configuration message successfully.
A configuration message has been processed successfully. Any configuration changes have been made and stored persistently.
No user action required.
2011-11-09 10:23:04.890221 3016 UserTrace BIP2638I: The MQ output node 'ConfigurationMessageFlow.outputNode' attempted to write a message to queue ''SYSTEM.BROKER.EXECUTIONGROUP.REPLY'' connected to queue manager ''WBRK_DEV.00''. The MQCC was '0' and the MQRC was '0'.
2011-11-09 10:23:04.890240 3016 UserTrace BIP2622I: Message successfully output by output node 'ConfigurationMessageFlow.outputNode' to queue ''SYSTEM.BROKER.EXECUTIONGROUP.REPLY'' on queue manager ''WBRK_DEV.00''.
2011-11-09 10:23:18.075300 1052 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ'.
2011-11-09 10:23:18.075439 1052 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-11-09 10:23:18.075485 1052 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-11-09 10:23:18.076467 1052 UserTrace BIP6061I: Parser type ''BLOB'' created on behalf of node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ' to handle portion of incoming message of length '2696' bytes beginning at offset '364'. Parser type selected based on value ''NONE'' from previous parser.
2011-11-09 10:23:18.230699 1052 UserTrace BIP4201I: Message propagated to out terminal from node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.ResetContentDescriptor'.
A reset content descriptor node has received a message and is propagating it to any nodes connected to its out terminal.
No user action required.
2011-11-09 10:23:21.430774 1052 UserTrace BIP4007I: Message propagated to 'out' terminal of node 'I001_PO.ACCB_I001_BO_PO_VISA.Map to VISA format'.
2011-11-09 10:23:21.464204 1052 UserTrace BIP2231E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ'. 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.
2011-11-09 10:23:21.464235 1052 RecoverableException BIP2230E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.Map to VISA format'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.Map to VISA format'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2011-11-09 10:23:21.464246 1052 RecoverableException BIP2488E: ('I001_PO.ACCB_I001_BO_PO_VISA_Compute.Main', '143.3') Error detected whilst executing the SQL statement ''PROPAGATE FINALIZE DEFAULT DELETE DEFAULT;''.
The message broker detected an error whilst executing the given statement. An exception has been thrown to cut short the SQL program.
See the following messages for details of the error.
2011-11-09 10:23:21.464254 1052 RecoverableException BIP2230E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_LOG.01.SetExpiry'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_LOG.01.SetExpiry'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2011-11-09 10:23:21.464263 1052 RecoverableException BIP2455E: Error casting character string '''''' to boolean.
The character string had the value ''''''. Only the character strings 'TRUE', 'FALSE', and 'UNKNOWN' can be cast to booleans.
Ensure that the character string being cast has one of the above values.
2011-11-09 10:23:21.582916 1052 Error BIP2232E: Error detected whilst handling a previous error in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.WBIMB_COMMON_TRACE_ERR.IsError'.
The message broker has detected an error in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.WBIMB_COMMON_TRACE_ERR.IsError' whilst handling a previous error.
See the following messages for details of the exception list associated with the original error. Thereafter messages will be associated with the new error.
2011-11-09 10:23:21.582956 1052 RecoverableException BIP2230E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.Map to VISA format'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.Map to VISA format'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2011-11-09 10:23:21.582973 1052 RecoverableException BIP2488E: ('I001_PO.ACCB_I001_BO_PO_VISA_Compute.Main', '143.3') Error detected whilst executing the SQL statement ''PROPAGATE FINALIZE DEFAULT DELETE DEFAULT;''.
The message broker detected an error whilst executing the given statement. An exception has been thrown to cut short the SQL program.
See the following messages for details of the error.
2011-11-09 10:23:21.582983 1052 RecoverableException BIP2230E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_LOG.01.SetExpiry'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_LOG.01.SetExpiry'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2011-11-09 10:23:21.582992 1052 RecoverableException BIP2455E: Error casting character string '''''' to boolean.
The character string had the value ''''''. Only the character strings 'TRUE', 'FALSE', and 'UNKNOWN' can be cast to booleans.
Ensure that the character string being cast has one of the above values.
2011-11-09 10:23:21.583301 1052 Error BIP2628E: Exception condition detected on input node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ'.
The input node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ' detected an error whilst processing a message. The message flow has been rolled-back and, if the message was being processed in a unit of work, it will remain on the input queue to be processed again. Following messages will indicate the cause of this exception.
Check the error messages which follow to determine why the exception was generated, and take action as described by those messages.
2011-11-09 10:23:21.583316 1052 RecoverableException BIP2230E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.WBIMB_COMMON_TRACE_ERR.IsError'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.WBIMB_COMMON_TRACE_ERR.IsError'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2011-11-09 10:23:21.583324 1052 RecoverableException BIP2455E: Error casting character string '''''' to boolean.
The character string had the value ''''''. Only the character strings 'TRUE', 'FALSE', and 'UNKNOWN' can be cast to booleans.
Ensure that the character string being cast has one of the above values.
2011-11-09 10:23:22.622575 1052 UserTrace BIP2631I: Backed out message being propagated to failure terminal; node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ'.
Node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.InputQ' has received a message which has previously been backed out because of a processing error in the message flow. The MQMD 'backoutCount' of the message exceeds (or equals) the 'backoutThreshold' defined for the WebSphere MQ input queue. The message broker is propagating the message to the failure terminal of the node.
Examine the other messages and the message flow to determine why the message is being backed out. Correct this situation if possible. Perform any local error recovery processing required.
2011-11-09 10:23:22.625274 1052 UserTrace BIP2638I: The MQ output node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.FailureQ' attempted to write a message to queue ''AQ.ACCB.I001_BO_PO_VISA_FAILURE.01'' connected to queue manager ''''. The MQCC was '0' and the MQRC was '0'.
2011-11-09 10:23:22.625297 1052 UserTrace BIP2622I: Message successfully output by output node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_VISA.01.FailureQ' to queue ''AQ.ACCB.I001_BO_PO_VISA_FAILURE.01'' on queue manager ''''.
2011-11-09 10:24:26.491039 3016 UserTrace BIP2632I: Message received and propagated to 'out' terminal of MQ input node 'ConfigurationMessageFlow.InputNode'.
2011-11-09 10:24:26.491161 3016 UserTrace BIP6060I: Parser type ''Properties'' created on behalf of node 'ConfigurationMessageFlow.InputNode' to handle portion of incoming message of length 0 bytes beginning at offset '0'.
2011-11-09 10:24:26.491195 3016 UserTrace BIP6061I: Parser type ''MQMD'' created on behalf of node 'ConfigurationMessageFlow.InputNode' to handle portion of incoming message of length '364' bytes beginning at offset '0'. Parser type selected based on value ''MQHMD'' from previous parser.
2011-11-09 10:24:26.491289 3016 UserTrace BIP6061I: Parser type ''XMLS'' created on behalf of node 'ConfigurationMessageFlow.InputNode' to handle portion of incoming message of length '229' bytes beginning at offset '364'. Parser type selected based on value ''XMLS'' from previous parser.
|
_________________
Do not underestimate the power of ... unit testing and continuous integration. |
|
| Back to top |
|
|
| marko.pitkanen |
| Posted: Wed Nov 09, 2011 11:00 am Post subject: |
|
|
Chevalier
Joined: 23 Jul 2008
Posts: 440
Location: Jamsa, Finland
|
Hi,
Have you tried to create a totally new bar file?
Can you get also debug level user trace out?
--
Marko |
|
| Back to top |
|
|
| mqjeff |
| Posted: Wed Nov 09, 2011 11:05 am Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
So here is the problem:
| Quote: |
2011-11-09 10:23:21.582983 1052 RecoverableException BIP2230E: Error detected whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_LOG.01.SetExpiry'.
The message broker detected an error whilst processing a message in node 'I001_PO.ACCB_I001_BO_PO_VISA.AQ.ACCB.I001_BO_PO_LOG.01.SetExpiry'. An exception has been thrown to cut short the processing of the message.
See the following messages for details of the error.
2011-11-09 10:23:21.582992 1052 RecoverableException BIP2455E: Error casting character string '''''' to boolean.
The character string had the value ''''''. Only the character strings 'TRUE', 'FALSE', and 'UNKNOWN' can be cast to booleans.
Ensure that the character string being cast has one of the above values. |
So look at the properties of the SetExpiry node. |
|
| Back to top |
|
|
| rekarm01 |
| Posted: Thu Nov 10, 2011 1:07 am Post subject: Re: Touched the boundary of code reusability in WBIMB Toolki |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 1415
|
| DaveCanto wrote: |
| You can also see it in today's usertrace:
|
Is that a debug-level usertrace, or a normal-level usertrace? It seems like there should be more detail there.
It might also be useful to add a Trace node between the 'Map to VISA format' and 'SetExpiry' nodes, to determine if there's a boolean element in the message that doesn't have a value. |
|
| Back to top |
|
|
| DaveCanto |
| Posted: Thu Nov 10, 2011 1:55 am Post subject: |
|
|
Novice
Joined: 01 Feb 2008
Posts: 11
Location: Belgium - EU
|
It's a normal usertrace, not a debug one. I'm sorry for that.
Actually I finally found the rootcause of this exception. I'm using 2 messageflow projects:
- 'MSF_atlascopco_ACCB_MESSAGING_v3_0' (ACCB) containing 'ACCB_I001_BO_PO_VISA.msgflow'
- 'MSF_atlascopco_WBIMB_COMMON' (COMMON) containing 'SF_Input.msgflow' and some other common subflows used in various messageflow projects
ACCB has a project reference to COMMON, because it's using the subflow 'SF_Input'. When browsing over the other reusable components in COMMON, I detected that there was a subflow called 'SF_Input_CustomErrors' containing unfinished source code (an incorrect definition of an external variable):
| Code: |
DECLARE TruncateMsg EXTERNAL BOOLEAN '';
|
which should have been
| Code: |
DECLARE TruncateMsg EXTERNAL BOOLEAN FALSE;
|
Here we have our failing cast from string to bool! I really looked over it, as I was not aware that 'SF_Input_CustomErrors' was even involved in my messageflow, only using 'SF_Input'. Normally it isn't, but because my messageflow has a reference to COMMON and 'TruncateMsg' is an external variable with a larger scope than a normal variable, my deployed bar-file knew about that incorrect defined external variable which caused an exception almost immediately after a new message entered my messageflow.
Lessons learned and we are going to be very careful next time when using external variables again in our future developments!
Anyway thanks for your help on this topic. Much appreciated!
_________________
Do not underestimate the power of ... unit testing and continuous integration. |
|
| Back to top |
|
|
|
|
