Latest revision as of 16:32, 9 June 2017

Internal

WildFly HornetQ-Based Messaging Subsystem

Relevance

EAP 6.4.15

Common Causes of Troubles

BLOCK policy. The queues seize up.
Always keep an eye on memory - automate gc log processing and failure detection.

Tracing Connection Creation

Set "org.hornetq.core.server" to TRACE.
Look for:

15:26:20,189 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: 1444597516, [id: 0x561acf0c, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=1dce22c5-4700-11e7-88d5-53aa0b02fcd0-1887100554-1781384206)) Connection created org.hornetq.core.remoting.impl.netty.NettyConnection@14335f60[local= /127.0.0.1:5445, remote=/127.0.0.1:49365]

Tracing Session Creation

Set "org.hornetq.core.client" to TRACE.
Look for:

15:26:50,240 TRACE [org.hornetq.core.client] (Old I/O server worker (parentId: 1444597516, [id: 0x561acf0c, /127.0.0.1:5445]), runningThread=Thread-2 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=1dce22c5-4700-11e7-88d5-53aa0b02fcd0-1887100554-1781384206)) handling packet PACKET(CreateSessionMessage)[type=30, channelID=1, packetObject=CreateSessionMessage]
...
15:26:50,245 TRACE [org.hornetq.core.client] (Old I/O server worker (parentId: 1444597516, [id: 0x561acf0c, /127.0.0.1:5445]), runningThread=Thread-2 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=1dce22c5-4700-11e7-88d5-53aa0b02fcd0-1887100554-1781384206)) Sending packet nonblocking PACKET(CreateSessionResponseMessage)[type=31, channelID=1, packetObject=CreateSessionResponseMessage] on channeID=1

Tracing a Message Send on the Server

Set "org.hornetq.core.client" to TRACE.
Look for:

15:51:00,366 TRACE [org.hornetq.core.client] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) handling packet PACKET(SessionSendMessage)[type=71, channelID=12, packetObject=SessionSendMessage,message=ServerMessage[messageID=0,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711]
15:51:00,366 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) ServerSessionPacketHandler::handlePacket,PACKET(SessionSendMessage)[type=71, channelID=12, packetObject=SessionSendMessage,message=ServerMessage[messageID=0,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711]
15:51:00,367 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) send(message=ServerMessage[messageID=16,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711, direct=true) being called
15:51:00,367 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) Routing message ServerMessage[messageID=16,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711 on binding=BindingsImpl [name=jms.queue.remote-playground]
15:51:00,368 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) Message after routed=ServerMessage[messageID=16,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711
15:51:00,368 TRACE [org.hornetq.journal] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) appendAddRecord::id=16, userRecordType=31, usedFile = JournalFileImpl: (hornetq-data-1.hq id = 1, recordID = 1)
15:51:00,369 TRACE [org.hornetq.journal] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) appendUpdateRecord::id=16, userRecordType=32, usedFile = JournalFileImpl: (hornetq-data-1.hq id = 1, recordID = 1)

...

15:51:00,371 DEBUG [org.hornetq.core.server] (Thread-4 (HornetQ-server-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-88477240)) QueueImpl[name=jms.queue.remote-playground, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c]]@6794cf5f doing deliver. messageReferences=0

The log entry regular expressions most reliably associated with handling a messages locally on the node is

grep "send(message=ServerMessage" | grep -v "address=jms\.queue\.hornetq\.management" | grep -v "_HQ_ROUTE_TO"

_HQ_ROUTE_TO is contained by messages being routed over bridges.

Another possibility is (to be further explored):

Routing message ServerMessage.*<queue-name>

printData

The data related to message, bindings and transaction records can be extracted using printData tool. Instructions how to run the tool can be find here:

https://access.redhat.com/solutions/516643

List Existing/Pending Transactions and Messages

https://access.redhat.com/solutions/1579893

@@ Line 2: / Line 2: @@
 * [[WildFly HornetQ-Based Messaging Subsystem#Subjects|WildFly HornetQ-Based Messaging Subsystem]]
+=Relevance=
+* EAP 6.4.15
+=Common Causes of Troubles=
+* BLOCK policy. The queues seize up.
+* Always keep an eye on memory - automate gc log processing and failure detection.
 =Tracing Connection Creation=
@@ Line 10: / Line 19: @@
 <pre>
 :26:20,189 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: 1444597516, [id: 0x561acf0c, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=1dce22c5-4700-11e7-88d5-53aa0b02fcd0-1887100554-1781384206)) Connection created org.hornetq.core.remoting.impl.netty.NettyConnection@14335f60[local= /127.0.0.1:5445, remote=/127.0.0.1:49365]
+</pre>
+=Tracing Session Creation=
+* Set "org.hornetq.core.client" to TRACE.
+* Look for:
+<pre>
+:26:50,240 TRACE [org.hornetq.core.client] (Old I/O server worker (parentId: 1444597516, [id: 0x561acf0c, /127.0.0.1:5445]), runningThread=Thread-2 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=1dce22c5-4700-11e7-88d5-53aa0b02fcd0-1887100554-1781384206)) handling packet PACKET(CreateSessionMessage)[type=30, channelID=1, packetObject=CreateSessionMessage]
+...
+:26:50,245 TRACE [org.hornetq.core.client] (Old I/O server worker (parentId: 1444597516, [id: 0x561acf0c, /127.0.0.1:5445]), runningThread=Thread-2 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=1dce22c5-4700-11e7-88d5-53aa0b02fcd0-1887100554-1781384206)) Sending packet nonblocking PACKET(CreateSessionResponseMessage)[type=31, channelID=1, packetObject=CreateSessionResponseMessage] on channeID=1
 </pre>
 =Tracing a Message Send on the Server=
+* Set "org.hornetq.core.client" to TRACE.
+* Look for:
+<pre>
+:51:00,366 TRACE [org.hornetq.core.client] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) handling packet PACKET(SessionSendMessage)[type=71, channelID=12, packetObject=SessionSendMessage,message=ServerMessage[messageID=0,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711]
+:51:00,366 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) ServerSessionPacketHandler::handlePacket,PACKET(SessionSendMessage)[type=71, channelID=12, packetObject=SessionSendMessage,message=ServerMessage[messageID=0,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711]
+:51:00,367 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) send(message=ServerMessage[messageID=16,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711, direct=true) being called
+:51:00,367 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) Routing message ServerMessage[messageID=16,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711 on binding=BindingsImpl [name=jms.queue.remote-playground]
+:51:00,368 TRACE [org.hornetq.core.server] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) Message after routed=ServerMessage[messageID=16,userID=a3061c1b-4703-11e7-9549-33f7fa104ebd,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=a3011303-4703-11e7-9549-33f7fa104ebd]]@1086285711
+:51:00,368 TRACE [org.hornetq.journal] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) appendAddRecord::id=16, userRecordType=31, usedFile = JournalFileImpl: (hornetq-data-1.hq id = 1, recordID = 1)
+:51:00,369 TRACE [org.hornetq.journal] (Old I/O server worker (parentId: -269084569, [id: 0xeff61867, /127.0.0.1:5445]), runningThread=Thread-1 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-1443861124-597302249)) appendUpdateRecord::id=16, userRecordType=32, usedFile = JournalFileImpl: (hornetq-data-1.hq id = 1, recordID = 1)
+...
+:51:00,371 DEBUG [org.hornetq.core.server] (Thread-4 (HornetQ-server-HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c-88477240)) QueueImpl[name=jms.queue.remote-playground, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=8448b231-4703-11e7-93ff-f1aa4df06f3c]]@6794cf5f doing deliver. messageReferences=0
+</pre>
+The log entry regular expressions most reliably associated with handling a messages locally on the node is
+<pre>
+grep "send(message=ServerMessage" | grep -v "address=jms\.queue\.hornetq\.management" | grep -v "_HQ_ROUTE_TO"
+</pre>
+_HQ_ROUTE_TO is contained by messages being routed over bridges.
+Another possibility is (to be further explored):
+<pre>
+Routing message ServerMessage.*<queue-name>
+</pre>
+=printData=
+The data related to message, bindings and transaction records can be extracted using printData tool. Instructions how to run the tool can be find here:
+{{External|https://access.redhat.com/solutions/516643}}
+=List Existing/Pending Transactions and Messages=
+{{External|https://access.redhat.com/solutions/1579893}}

WildFly HornetQ-Based Messaging Subsystem Troubleshooting: Difference between revisions

Latest revision as of 16:32, 9 June 2017

Contents

Internal

Relevance

Common Causes of Troubles

Tracing Connection Creation

Tracing Session Creation

Tracing a Message Send on the Server

printData

List Existing/Pending Transactions and Messages

Navigation menu

WildFly HornetQ-Based Messaging Subsystem Troubleshooting: Difference between revisions

Latest revision as of 16:32, 9 June 2017

Internal

Relevance

Common Causes of Troubles

Tracing Connection Creation

Tracing Session Creation

Tracing a Message Send on the Server

printData

List Existing/Pending Transactions and Messages

Navigation menu

Search