DLQ - Cause logging?
I'm wondering if there is some way to figure out why a message gets to DLQ. Past experience is you'll see some sort of exception, but in this case messages are going straight to DLQ after the max size was reached for the queue. First off, the setup is:
- Persisted JMS (MySQL)
- JBoss 3.2
- Queues only
- Max size for queues is five
- Custom DLQ handler
- No MDB timeout/expiration set (to my knowledge)
- MDB configured for five instances max
- Logging has root element pointing to a file, all other severities turned down to TRACE.
What is occurring is 25 messages are sent to a queue name QUEUE.Preprocessor - no problem. Where the issue comes into play is immediately after five instances fire up two of the twenty five messages goto DLQ. The five that were/are running complete - no error. After two goto DLQ, the rest of the messages in the queue appear to processes fine. What I can't figure out is why the messages goto DLQ in the first place. I have cranked the logging down (see below snippet) but it doesn't show me how messages sent the QUEUE.Preprocessor got to DLQ. Past experience shows that normally you'll get some sort of exception, such as message was corrupt or exception was thrown by the MDB but in this situation there's nothing in the log file.
Is there any other DLQ interrogation, other than cranking down the logging, that can be done to see why a message is sent to DLQ? Any help or suggestions is very much appreciated.
Thanks!
Randall
Here's a short log snippet:
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-12077258586628] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-12077258586628
jmsTimeStamp : 1207725858662
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-12077258586628] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-12077258586628
jmsTimeStamp : 1207725858662
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [engine.CacheSynchronization] 433498 transaction after completion callback, status: 3
2008-04-09 15:24:20,098 DEBUG [engine.CacheSynchronization] 433498 transaction after completion callback, status: 3
2008-04-09 15:24:20,098 DEBUG [impl.SessionImpl] 433498 transaction completion
2008-04-09 15:24:20,098 DEBUG [impl.SessionImpl] 433498 transaction completion
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-120772585867710] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585867710
jmsTimeStamp : 1207725858677
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-120772585867710] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585867710
jmsTimeStamp : 1207725858677
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-120772585867711] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585867711
jmsTimeStamp : 1207725858677
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-120772585867711] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585867711
jmsTimeStamp : 1207725858677
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-120772585867713] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585867713
jmsTimeStamp : 1207725858677
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,098 DEBUG [plugins.LogInterceptor] 433498 Invoke: [ID:29-120772585867713] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585867713
jmsTimeStamp : 1207725858677
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,114 DEBUG [plugins.LogInterceptor] 433514 Invoke: [ID:29-120772585902114] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585902114
jmsTimeStamp : 1207725859021
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,114 DEBUG [plugins.LogInterceptor] 433514 Invoke: [ID:29-120772585902114] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.PreProcessor
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:29-120772585902114
jmsTimeStamp : 1207725859021
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:29
}
})
2008-04-09 15:24:20,130 DEBUG [local.LocalManagedConnectionFactory] 433530 Using properties: {user=streetwise, password=--hidden--}
2008-04-09 15:24:20,130 DEBUG [local.LocalManagedConnectionFactory] 433530 Using properties: {user=streetwise, password=--hidden--}
2008-04-09 15:24:20,130 DEBUG [local.LocalManagedConnectionFactory] 433530 Using properties: {user=streetwise, password=--hidden--}
2008-04-09 15:24:20,130 DEBUG [local.LocalManagedConnectionFactory] 433530 Using properties: {user=streetwise, password=--hidden--}
2008-04-09 15:24:20,130 DEBUG [plugins.LogInterceptor] 433530 Invoke: [ID:32-12077258607881] onMessage(org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.DLQ
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:32-12077258607881
jmsTimeStamp : 1207725860788
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {JBOSS_ORIG_MESSAGEID=ID:29-12077258586629, JBOSS_ORIG_DESTINATION=QUEUE.PreProcessor}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:32
}
})