WildFly HornetQ-Based Messaging Subsystem Troubleshooting: Difference between revisions

From NovaOrdis Knowledge Base
Jump to navigation Jump to search
Line 29: Line 29:


<pre>
<pre>
15:26:50,275 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(SessionSendMessage)[type=71, channelID=12, packetObject=SessionSendMessage,message=ServerMessage[messageID=0,userID=42b3a20d-4700-11e7-aa56-913ccdb899c2,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=42ae71e5-4700-11e7-aa56-913ccdb899c2]]@395826524]
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:26:50,276 TRACE [org.hornetq.core.server] (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)) Routing message ServerMessage[messageID=16,userID=42b3a20d-4700-11e7-aa56-913ccdb899c2,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=42ae71e5-4700-11e7-aa56-913ccdb899c2]]@395826524 on binding=BindingsImpl [name=jms.queue.remote-playground]
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:26:50,276 TRACE [org.hornetq.core.server] (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)) Message after routed=ServerMessage[messageID=16,userID=42b3a20d-4700-11e7-aa56-913ccdb899c2,priority=4, bodySize=314,expiration=0, durable=true, address=jms.queue.remote-playground,properties=TypedProperties[__HQ_CID=42ae71e5-4700-11e7-aa56-913ccdb899c2]]@395826524


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
</pre>
</pre>

Revision as of 19:57, 1 June 2017

Internal

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