Every project has its own way to capture the logs and they are mostly falls under one of these categories
- Subflows
- Monitoring Profiles
And these logs are stored either as files or in database tables. So, here I’m going to explain how to use Log4j to capture the logs from monitoring profiles. Note, we’re not going to use Log4j node but instead we use a simple log4j configuration file and some java code to capture all the elements available from the monitoring profiles.
Let us take a simple flow to understand.

And the monitoring configurations for MQInput Node are




So, the monitoring profile is ready and I’m going to use MQTT instead of MQ to get the monitoring event messages.


MQTT is enabled and the port number is 11884. Let us test the monitoring profile configured and see how the event message looks like.


The event monitoring messages are published in topic IBM/IntegrationBus/IB10NODE/Monitoring/default/# and the message looks like
<wmb:event xmlns:wmb="http://www.ibm.com/xmlns/prod/websphere/messagebroker/6.1.0/monitoring/event"> <wmb:eventPointData> <wmb:eventData wmb:productVersion="100011" wmb:eventSchemaVersion="6.1.0.3" wmb:eventSourceAddress="MQ Input.transaction.Start"> <wmb:eventIdentity wmb:eventName="OrderReceived"/> <wmb:eventSequence wmb:creationTime="2020-06-01T02:02:32.402892Z" wmb:counter="1"/> <wmb:eventCorrelation wmb:localTransactionId="f8a1af6d-013b-4420-9c1b-baf23d5e10a4-5" wmb:parentTransactionId="" wmb:globalTransactionId=""/> </wmb:eventData> <wmb:messageFlowData> <wmb:broker wmb:name="IB10NODE" wmb:UUID="b7d2e6dd-0b36-4728-9015-818133dbeb14"/> <wmb:executionGroup wmb:name="default" wmb:UUID="61704de3-b47c-4b23-b95f-0ffd934fdcb1"/> <wmb:messageFlow wmb:uniqueFlowName="IB10NODE.default.TestMon.TestMon" wmb:name="TestMon" wmb:UUID="429ff9ef-1c8d-48c1-bf42-99ac3bd247fb" wmb:threadId="21980"/> <wmb:node wmb:nodeLabel="MQ Input" wmb:nodeType="ComIbmMQInputNode" wmb:detail="IN.Q"/> </wmb:messageFlowData> </wmb:eventPointData> <wmb:applicationData xmlns=""> <wmb:complexContent wmb:elementName="MQMD"> <MQMD> <SourceQueue>IN.Q</SourceQueue> <Transactional>true</Transactional> <Encoding>273</Encoding> <CodedCharSetId>1208</CodedCharSetId> <Format>MQSTR </Format> <Version>2</Version> <Report>0</Report> <MsgType>8</MsgType> <Expiry>-1</Expiry> <Feedback>0</Feedback> <Priority>0</Priority> <Persistence>0</Persistence> <MsgId>414d5120494942763130514d475220204064d15e10000105</MsgId> <CorrelId>000000000000000000000000000000000000000000000000</CorrelId> <BackoutCount>0</BackoutCount> <ReplyToQ> </ReplyToQ> <ReplyToQMgr>IIBv10QMGR </ReplyToQMgr> <UserIdentifier>vaithu </UserIdentifier> <AccountingToken>160105150000002d74cc5dfa721e73431607412b32030000000000000000000b</AccountingToken> <ApplIdentityData> </ApplIdentityData> <PutApplType>28</PutApplType> <PutApplName>vaithu</PutApplName> <PutDate>2020-06-01</PutDate> <PutTime>02:02:32.480</PutTime> <ApplOriginData> </ApplOriginData> <GroupId>000000000000000000000000000000000000000000000000</GroupId> <MsgSeqNumber>1</MsgSeqNumber> <Offset>0</Offset> <MsgFlags>0</MsgFlags> <OriginalLength>-1</OriginalLength> </MQMD> </wmb:complexContent> </wmb:applicationData> <wmb:bitstreamData> <wmb:bitstream wmb:encoding="base64Binary">TUQgIAIAAAAAAAAACAAAAP////8AAAAAEQEAALgEAABNUVNUUiAgIAAAAAAAAAAAQU1RIElJQnYxMFFNR1IgIEBk0V4QAAEFAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAACAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIElJQnYxMFFNR1IgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIHN4cDI2NyAgICAgIBYBBRUAAAAtdMxd+nIec0MWB0ErMgMAAAAAAAAAAAALICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAcAAAAZ21haWwuc3Jpbml2YXNhLkFwcGxpY2F0aW9uIDIwMjAwNjAxMDIwMjMyNDggICAgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAAAAAAAAAAAAAA/////zxPcmRlcnM+CiAgIDxPcmRlcj4KICAgICAgPEN1c3RvbWVySUQ+R1JFQUw8L0N1c3RvbWVySUQ+CiAgICAgIDxFbXBsb3llZUlEPjY8L0VtcGxveWVlSUQ+CiAgICAgIDxPcmRlckRhdGU+MTk5Ny0wNS0wNlQwMDowMDowMDwvT3JkZXJEYXRlPgogICAgICA8UmVxdWlyZWREYXRlPjE5OTctMDUtMjBUMDA6MDA6MDA8L1JlcXVpcmVkRGF0ZT4KICAgICAgPFNoaXBJbmZvIFNoaXBwZWREYXRlPSIxOTk3LTA1LTA5VDAwOjAwOjAwIj4KICAgICAgICAgPFNoaXBWaWE+MjwvU2hpcFZpYT4KICAgICAgICAgPEZyZWlnaHQ+My4zNTwvRnJlaWdodD4KICAgICAgICAgPFNoaXBOYW1lPkdyZWF0IExha2VzIEZvb2QgTWFya2V0PC9TaGlwTmFtZT4KICAgICAgICAgPFNoaXBBZGRyZXNzPjI3MzIgQmFrZXIgQmx2ZC48L1NoaXBBZGRyZXNzPgogICAgICAgICA8U2hpcENpdHk+RXVnZW5lPC9TaGlwQ2l0eT4KICAgICAgICAgPFNoaXBSZWdpb24+T1I8L1NoaXBSZWdpb24+CiAgICAgICAgIDxTaGlwUG9zdGFsQ29kZT45NzQwMzwvU2hpcFBvc3RhbENvZGU+CiAgICAgICAgIDxTaGlwQ291bnRyeT5VU0E8L1NoaXBDb3VudHJ5PgogICAgICA8L1NoaXBJbmZvPgogICA8L09yZGVyPgo8L09yZGVycz4=</wmb:bitstream> </wmb:bitstreamData> </wmb:event>
Let us see what happens when there is an exception. To generate an exception, I’m just going to make the out queue name to a random non-existing queue OUTaa.Q and now the monitoring event with Exception tree looks like
<wmb:event xmlns:wmb="http://www.ibm.com/xmlns/prod/websphere/messagebroker/6.1.0/monitoring/event"> <wmb:eventPointData> <wmb:eventData wmb:productVersion="100011" wmb:eventSchemaVersion="6.1.0.3" wmb:eventSourceAddress="MQ Input.transaction.Rollback"> <wmb:eventIdentity wmb:eventName="OrderRollback"/> <wmb:eventSequence wmb:creationTime="2020-06-01T02:17:30.450741Z" wmb:counter="2"/> <wmb:eventCorrelation wmb:localTransactionId="47ab24c4-91c8-48b6-91a2-e0cc0393085b-1" wmb:parentTransactionId="" wmb:globalTransactionId=""/> </wmb:eventData> <wmb:messageFlowData> <wmb:broker wmb:name="IB10NODE" wmb:UUID="b7d2e6dd-0b36-4728-9015-818133dbeb14"/> <wmb:executionGroup wmb:name="default" wmb:UUID="61704de3-b47c-4b23-b95f-0ffd934fdcb1"/> <wmb:messageFlow wmb:uniqueFlowName="IB10NODE.default.TestMon.TestMon" wmb:name="TestMon" wmb:UUID="429ff9ef-1c8d-48c1-bf42-99ac3bd247fb" wmb:threadId="8076"/> <wmb:node wmb:nodeLabel="MQ Input" wmb:nodeType="ComIbmMQInputNode" wmb:detail="IN.Q"/> </wmb:messageFlowData> </wmb:eventPointData> <wmb:applicationData xmlns=""> <wmb:complexContent wmb:elementName="ExceptionList"> <ExceptionList> <RecoverableException> <File>F:\build\S1000_slot1\S1000_P\src\DataFlowEngine\TemplateNodes\ImbOutputTemplateNode.cpp</File> <Line>303</Line> <Function>ImbOutputTemplateNode::processMessageAssemblyToFailure</Function> <Type>ComIbmMQOutputNode</Type> <Name>TestMon#FCMComposite_1_2</Name> <Label>TestMon.MQ Output</Label> <Catalog>BIPmsgs</Catalog> <Severity>3</Severity> <Number>2230</Number> <Text>Caught exception and rethrowing</Text> <Insert> <Type>14</Type> <Text>TestMon.MQ Output</Text> </Insert> <MessageException> <File>F:\build\S1000_slot1\S1000_P\src\DataFlowEngine\Connectors\mqconnector\MQConnection.cpp</File> <Line>1003</Line> <Function>MQConnection::acquireOutputQueueHandle</Function> <Type></Type> <Name></Name> <Label></Label> <Catalog>BIPmsgs</Catalog> <Severity>3</Severity> <Number>2666</Number> <Text>Failed to open queue</Text> <Insert> <Type>2</Type> <Text>-1</Text> </Insert> <Insert> <Type>5</Type> <Text>MQW101</Text> </Insert> <Insert> <Type>2</Type> <Text>2085</Text> </Insert> <Insert> <Type>5</Type> <Text></Text> </Insert> <Insert> <Type>5</Type> <Text>IIBv10QMGR</Text> </Insert> <Insert> <Type>5</Type> <Text>OUTaa.Q</Text> </Insert> <Insert> <Type>2</Type> <Text>2</Text> </Insert> </MessageException> </RecoverableException> </ExceptionList> </wmb:complexContent> </wmb:applicationData> </wmb:event>
Now, we know how the monitoring profile and monitoring events works. Let us develop a solution which will accept these messages and log them as we needed. For this, I’ve another message flow and it looks like

The MQTTSubscribe node is used to get the published event monitoring messages and the Java compute node is used to decipher the event monitoring XML message and log them. A sample log file looks like
2020-05-31 22:54:29.036 [Thread-49] INFO - ----------------------------------------Transaction Starts--------------------------------------------------------- 2020-05-31 22:54:29.058 [Thread-49] INFO - Event Number :2 2020-05-31 22:54:30.001 [Thread-49] ERROR - Data Element Name :ExceptionList 2020-05-31 22:54:32.301 [Thread-49] ERROR - Error Message :Failed to open queue;MQW101;2085;IIBv10QMGR;OUTaa.Q; 2020-05-31 22:54:32.301 [Thread-49] INFO - ----------------------------------------Transaction Ends--------------------------------------------------------- 2020-05-31 22:54:36.142 [Thread-49] INFO - ----------------------------------------Transaction Starts--------------------------------------------------------- 2020-05-31 22:54:36.156 [Thread-49] INFO - Event Number :1 2020-05-31 22:54:37.475 [Thread-49] INFO - Data Element Name :MQMD 2020-05-31 22:54:37.476 [Thread-49] INFO - *********************************************************************** 2020-05-31 22:54:37.477 [Thread-49] INFO - SourceQueue : IN.Q 2020-05-31 22:54:37.478 [Thread-49] INFO - Transactional : true 2020-05-31 22:54:37.478 [Thread-49] INFO - Encoding : 273 2020-05-31 22:54:37.480 [Thread-49] INFO - CodedCharSetId : 1208 2020-05-31 22:54:37.480 [Thread-49] INFO - Format : MQSTR 2020-05-31 22:54:37.481 [Thread-49] INFO - Version : 2 2020-05-31 22:54:37.482 [Thread-49] INFO - Report : 0 2020-05-31 22:54:37.483 [Thread-49] INFO - MsgType : 8 2020-05-31 22:54:37.484 [Thread-49] INFO - Expiry : -1 2020-05-31 22:54:37.484 [Thread-49] INFO - Feedback : 0 2020-05-31 22:54:37.485 [Thread-49] INFO - Priority : 0 2020-05-31 22:54:37.485 [Thread-49] INFO - Persistence : 0 2020-05-31 22:54:37.486 [Thread-49] INFO - MsgId : 414d5120494942763130514d475220204064d15e1000010d 2020-05-31 22:54:37.486 [Thread-49] INFO - CorrelId : 000000000000000000000000000000000000000000000000 2020-05-31 22:54:37.487 [Thread-49] INFO - BackoutCount : 1 2020-05-31 22:54:37.487 [Thread-49] INFO - ReplyToQ : 2020-05-31 22:54:37.487 [Thread-49] INFO - ReplyToQMgr : IIBv10QMGR 2020-05-31 22:54:37.488 [Thread-49] INFO - UserIdentifier : vaithu 2020-05-31 22:54:37.488 [Thread-49] INFO - AccountingToken : 160105150000002d74cc5dfa721e73431607412b32030000000000000000000b 2020-05-31 22:54:37.488 [Thread-49] INFO - ApplIdentityData : 2020-05-31 22:54:37.490 [Thread-49] INFO - PutApplType : 28 2020-05-31 22:54:37.490 [Thread-49] INFO - PutApplName : vaithu 2020-05-31 22:54:37.491 [Thread-49] INFO - PutDate : 2020-06-01 2020-05-31 22:54:37.492 [Thread-49] INFO - PutTime : 02:54:15.150 2020-05-31 22:54:37.493 [Thread-49] INFO - ApplOriginData : 2020-05-31 22:54:37.493 [Thread-49] INFO - GroupId : 000000000000000000000000000000000000000000000000 2020-05-31 22:54:37.494 [Thread-49] INFO - MsgSeqNumber : 1 2020-05-31 22:54:37.494 [Thread-49] INFO - Offset : 0 2020-05-31 22:54:37.494 [Thread-49] INFO - MsgFlags : 0 2020-05-31 22:54:37.495 [Thread-49] INFO - OriginalLength : -1 2020-05-31 22:54:37.495 [Thread-49] INFO - *********************************************************************** 2020-05-31 22:54:37.495 [Thread-49] INFO - OrderReceived Payload : MD ÿÿÿÿ ¸ MQSTR AMQ IIBv10QMGR @dÑ^ IIBv10QMGR vaithu -tÌ]úrsCA+2 vaithu 2020060102541515 ÿÿÿÿ<Orders> <Order> <CustomerID>GREAL</CustomerID> <EmployeeID>6</EmployeeID> <OrderDate>1997-05-06T00:00:00</OrderDate> <RequiredDate>1997-05-20T00:00:00</RequiredDate> <ShipInfo ShippedDate="1997-05-09T00:00:00"> <ShipVia>2</ShipVia> <Freight>3.35</Freight> <ShipName>Great Lakes Food Market</ShipName> <ShipAddress>2732 Baker Blvd.</ShipAddress> <ShipCity>Eugene</ShipCity> <ShipRegion>OR</ShipRegion> <ShipPostalCode>97403</ShipPostalCode> <ShipCountry>USA</ShipCountry> </ShipInfo> </Order> </Orders> 2020-05-31 22:54:37.497 [Thread-49] INFO - ----------------------------------------Transaction Ends--------------------------------------------------------- 2020-05-31 22:54:41.125 [Thread-49] INFO - ----------------------------------------Transaction Starts--------------------------------------------------------- 2020-05-31 22:54:41.135 [Thread-49] INFO - Event Number :2 2020-05-31 22:54:42.179 [Thread-49] ERROR - Data Element Name :ExceptionList 2020-05-31 22:54:44.299 [Thread-49] ERROR - Error Message :Failed to open queue;MQW101;2085;IIBv10QMGR;OUTaa.Q; 2020-05-31 22:54:44.299 [Thread-49] INFO - ----------------------------------------Transaction Ends---------------------------------------------------------
Here each event message is clearly separated and easily readable. The exception handler captures the right error message and ignores all other unnecessary information. So, we know the key elements, input and output payload and the exception message. Since we’re using monitoring profile, there is no need for any custom subflows and this solution is production tested code and works fantastically, thanks to log4j settings.
2020-05-31 22:54:41.125 [Thread-49] INFO - ----------------------------------------Transaction Starts--------------------------------------------------------- 2020-05-31 22:54:41.135 [Thread-49] INFO - Event Number :2 2020-05-31 22:54:42.179 [Thread-49] ERROR - Data Element Name :ExceptionList 2020-05-31 22:54:44.299 [Thread-49] ERROR - Error Message :Failed to open queue;MQW101;2085;IIBv10QMGR;OUTaa.Q; 2020-05-31 22:54:44.299 [Thread-49] INFO - ----------------------------------------Transaction Ends---------------------------------------------------------
All these logs are categorically separated like nodename/servername/flowname so that it is easy to identify the log files. The log files gets rolled up automatically and each log file size is 10MB as these are controlled by the log4j settings.
All you’ve to do is, just enable monitoring and see the logs in the folder configured in the log4j config file.
If you’d like to understand how the log4j file looks like and the Java code used, there is a session on this next week Sunday.
Contact us at support@vaithu.com for more details and to purchase.