11 Replies Latest reply on Apr 5, 2004 4:52 AM by adrian.brock

Messages disappear - jboss 3.2.3

moppersmurf Apr 1, 2004 6:21 AM

Hi,

JBoss version 3.2.3

We've a system with a session bean that publishes messages on a topic. Message driven beans are subscribed to the topic. The system works fine if a approx 3 messages per seconds are posted. When more messages are posted, messages appear to disappear. They are sent to the topic but never 'reach' a message driven bean. The maximum amount of MDBs is set to 1000, much more than necessary so that shouldn't be the problem.

If I look in the logfile, the message appears to disappear somewhere when sent to the topic.

Directly below some loggings of a message that 'disappears'. Below that some loggings of a correctly handled message are listed. The logging 'TOPIC.testTopic->addMessage' never appears for messages that disappear. Any idea what might be the problem?

---- LOG
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818792578
jmsPriority : 1
jmsMessageID : ID:258-108081878257864
jmsTimeStamp : 1080818782578
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:true
msgReadOnly : false
producerClientId: ID:258
}
}
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [durpublisher, publisher, guest]
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778 wasHard=true
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.MessageCache] add locks release6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.MessageCache] remove lock release message 6299 msg=1755 hard soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=17704026 clear= false reset=false
...........
---- END LOG

If I compare it with loggings of a messages that don't have problems, I see text in the logfile like 'TOPIC.testTopic->addMessage' which I miss for the messages that 'disappear'.

Correctly handled message:

---- LOG
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818247125
jmsPriority : 1
jmsMessageID : ID:15-108081823712512
jmsTimeStamp : 1080818237125
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:true
msgReadOnly : false
producerClientId: ID:15
}
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [durpublisher, publisher, guest]
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] add lock aquire message 105 msg=37 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:4.-2147483648 priority=1 hashCode=8469194
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] add lock aquire lruCache 105 msg=37 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:4.-2147483648 priority=1 hashCode=8469194
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] add locks release105 msg=37 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:4.-2147483648 priority=1 hashCode=8469194
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] Memory usage serverity=1.0
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] Need to soften 2 messages
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] soften lock acquire 104 msg=36 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=16579856
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageReference] makeSoft lock aquire 104 msg=36 hard NOT_STORED PERSISTENT

....

2004-04-01 12:17:17,140 TRACE [org.jboss.mq.SpyConnectionConsumer] SpyConnectionConsumer:TOPIC.testTopic->addMessage(mes=org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818247125
jmsPriority : 1
jmsMessageID : ID:15-108081823712512
jmsTimeStamp : 1080818237125
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:15
}
---- END LOG

1. Re: JBoss MDB listening to OracleAQ queue

adrian.brock Apr 1, 2004 6:21 AM (in response to moppersmurf)

How todo which?

1) Provide an alternate implemetnation to this:
http://cvs.sourceforge.net/viewcvs.py/jboss/jboss/src/main/org/jboss/jms/jndi/JBossMQProvider.java?rev=1.9&view=auto
2) Use this mbean to add an external context somewhere in jboss's tree
http://cvs.sourceforge.net/viewcvs.py/jboss/jboss/src/main/org/jboss/naming/ExternalContext.java?rev=1.17&view=auto
There are examples of (2) if you use search and avoid all the fumbling.

Regards,
Adrian
Actions
2. Re: Messages disappear - jboss 3.2.3

adrian.brock Apr 1, 2004 6:44 AM (in response to moppersmurf)

You haven't posted the log all the way through to conclusion.
You should see
RETURN: addMessage
when the add message has finished.

In the second log, you have the problem that memory is tight so JBossMQ is
pushing messages onto disk.
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] Memory usage serverity=1.0
What are your memory and message cache settings?

Regards,
Adrian
Actions
3. Re: Messages disappear - jboss 3.2.3

moppersmurf Apr 1, 2004 6:57 AM (in response to moppersmurf)

"adrian@jboss.org" wrote:
You haven't posted the log all the way through to conclusion.
You should see
RETURN: addMessage
when the add message has finished.

In the second log, you have the problem that memory is tight so JBossMQ is
pushing messages onto disk.
2004-04-01 12:17:17,125 TRACE [org.jboss.mq.server.MessageCache] Memory usage serverity=1.0
What are your memory and message cache settings?

Regards,
Adrian

Thanks for the fast response!

The second log is of a message that doesn't give any problem. I posted it for the comparison. But the memory in the machine is 2GB, min is 1024 en max 1536. If I inspect the memory there is always plenty of free memory.

The first log more complete:

2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818792578
jmsPriority : 1
jmsMessageID : ID:258-108081878257864
jmsTimeStamp : 1080818782578
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:true
msgReadOnly : false
producerClientId: ID:258
}
}
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [durpublisher, publisher, guest]
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778 wasHard=true
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.MessageCache] add locks release6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846
2004-04-01 12:26:22,578 TRACE [org.jboss.mq.server.MessageCache] remove lock release message 6299 msg=1755 hard soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=17704026 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818792578
jmsPriority : 1
jmsMessageID : ID:130-108081878257897
jmsTimeStamp : 1080818782578
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:true
msgReadOnly : false
producerClientId: ID:130
}
}
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyXAResource] Start xid=XidImpl [FormatId=257, GlobalId=mls-dev//176625, BranchQual=], flags=0
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6291 msg=1750 soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=7684703 clear=true reset=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] makeSoft lock released 6299 msg=1755 soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=17704026
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [durpublisher, publisher, guest]
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyXAResourceManager] Converting tx anonXid=-9223372036854774738, xid=XidImpl [FormatId=257, GlobalId=mls-dev//176625, BranchQual=]
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6291 msg=1750 soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=7684703 clear= true reset=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpySession] Setting current tx org.jboss.mq.SpyTopicSession@a0a36 xid=XidImpl [FormatId=257, GlobalId=mls-dev//176625, BranchQual=] previous: -9223372036854774738
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] Memory usage serverity=1.0
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6324 msg=1761 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=2355778
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.Connection] Starting connection, ClientID=ID:136
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] Using optimized 1p commit to control TX.
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] Need to soften 38 messages
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : setEnabled
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
2004-04-01 12:26:22,593 TRACE [org.jboss.ejb.plugins.jms.JMSContainerInvoker] processing message: org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818782765
jmsPriority : 1
jmsMessageID : ID:132-108081877276574
jmsTimeStamp : 1080818772765
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:132
}
}
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSessionPool] getting a server session
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] soften lock acquire 6304 msg=2272 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6291 msg=1750 soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=7684703 clear= true reset=true
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSessionPool] using server session: org.jboss.jms.asf.StdServerSession@216b59
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.ClientConsumer] ClientConsumer:ID:136->setEnabled(enabled=true)
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] makeSoft lock aquire 6304 msg=2272 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6291 msg=1750 soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=7684703
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : setEnabled
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] Memory usage serverity=1.0
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyConnectionConsumer] SpyConnectionConsumer:QUEUE.testQueue Starting the ServerSession.
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Saving message to storage 6304 msg=2272 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6291 msg=1750 soft REMOVED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=7684703
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] Need to soften 38 messages
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] soften lock acquire 6304 msg=2272 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080818792593
jmsPriority : 1
jmsMessageID : ID:136-108081878259387
jmsTimeStamp : 1080818782593
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:true
msgReadOnly : false
producerClientId: ID:136
}
}
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=7684703 clear= true reset=true
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] starting invokes on server session
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : transact
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [durpublisher, publisher, guest]
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] running...
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : receive
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] onMessage done
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyXAResourceManager] Starting tx with new xid=-9223372036854774047
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] recycling...
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -1
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpySession] Setting current tx org.jboss.mq.SpyTopicSession@1635484 xid=-9223372036854774047 previous: null
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Saved message to storage 6304 msg=2272 hard STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSessionPool] recycled server session: org.jboss.jms.asf.StdServerSession@91d7c
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:3/b1f54387dcb822beb90286e64542a365 subId=-2147483648
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyXAResourceManager] Ack'ing message xid=-9223372036854774047
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] finished run
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6304 msg=2272 hard soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051 clear=false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [publisher, guest]
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] onMessage running (pool, session, xaSession, useLocalTX): , org.jboss.mq.SpyTopicSession@1635484, org.jboss.mq.SpyTopicSession@1635484, true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6304 msg=2272 hard soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyXAResource] Start xid=XidImpl [FormatId=257, GlobalId=mls-dev//176635, BranchQual=], flags=0
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6304 msg=2272 hard soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpyXAResourceManager] Converting tx anonXid=-9223372036854774047, xid=XidImpl [FormatId=257, GlobalId=mls-dev//176635, BranchQual=]
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock release message 6304 msg=2272 hard soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.SpySession] Setting current tx org.jboss.mq.SpyTopicSession@1635484 xid=XidImpl [FormatId=257, GlobalId=mls-dev//176635, BranchQual=] previous: -9223372036854774047
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] makeSoft lock released 6304 msg=2272 soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.jms.asf.StdServerSession] Using optimized 1p commit to control TX.
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] makeSoft lock aquire 6304 msg=2272 soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27689051
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939
2004-04-01 12:26:22,593 TRACE [org.jboss.ejb.plugins.jms.JMSContainerInvoker] processing message: org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.testQueue
jmsDeliveryMode : 2
jmsExpiration : 1080818902328
jmsPriority : 1
jmsMessageID : ID:1130-10808187823281
jmsTimeStamp : 1080818782328
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:1130
}
}
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] run lock aquire, validateSoftReferenceDepth
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] Memory usage serverity=1.0
Header {
jmsDestination : QUEUE.testQueue
jmsDeliveryMode : 2
jmsExpiration : 1080818902328
jmsPriority : 1
jmsMessageID : ID:1130-10808187823281
jmsTimeStamp : 1080818782328
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:1130
}
}
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] Need to soften 37 messages
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] soften lock acquire 6301 msg=1756 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=15703456
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] makeSoft lock aquire 6301 msg=1756 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=15703456
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939 wasHard=true
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6329 msg=2282 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=17987846
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6301 msg=1756 hard soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=15703456 clear=false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6301 msg=1756 hard soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=15703456 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6301 msg=1756 hard soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=15703456 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6325 msg=1762 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=32893939
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6216 msg=2243 soft STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=12680240
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] add lock aquire message 6330 msg=2283 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:4.-2147483648 priority=1 hashCode=1257809
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] remove lock release message 6301 msg=1756 hard soft STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=15703456 clear= false reset=false
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.MessageCache] add lock aquire lruCache 6330 msg=2283 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:4.-2147483648 priority=1 hashCode=1257809
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
2004-04-01 12:26:22,593 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
Actions
4. Re: Messages disappear - jboss 3.2.3

adrian.brock Apr 1, 2004 7:13 AM (in response to moppersmurf)

But the default message cache size is 50M and 60M see persistence service.
Once memory exceeds 50M you will hit the stage where jbossmq tries to move
messages onto disk trying to keep memory below 60M.

Regards,
Adrian
Actions
5. Re: Messages disappear - jboss 3.2.3

moppersmurf Apr 1, 2004 7:23 AM (in response to moppersmurf)

"adrian@jboss.org" wrote:
But the default message cache size is 50M and 60M see persistence service.
Once memory exceeds 50M you will hit the stage where jbossmq tries to move
messages onto disk trying to keep memory below 60M.

Regards,
Adrian

Ah, I see. I've changed the hsqldb-jdbc2-service.xml file. But I don't think that causes the disappearing messages, does it? But I'm goin to test it right now.
Actions
6. Re: Messages disappear - jboss 3.2.3

moppersmurf Apr 1, 2004 8:01 AM (in response to moppersmurf)

I've changed the cache size settings. No memory problems are logged anymore. But the problem of the disappearing messages still exist.

Below a new log (hope it is not too big). The message with ID 1080826270812105 is sent to the topic, but it never seems to actually be added to the topic.

2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6649 msg=1712 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=31951808 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6528 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=20325696
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6651 msg=1714 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=30726959 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6535 msg=2430 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14022169
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6640 msg=1703 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=21041004
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : TOPIC.testTopic
jmsDeliveryMode : 2
jmsExpiration : 1080826280812
jmsPriority : 1
jmsMessageID : ID:74-1080826270812105
jmsTimeStamp : 1080826270812
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {provider=SIM}
jmsPropertiesReadWrite:true
msgReadOnly : false
producerClientId: ID:74
}
}
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6528 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=20325696 clear=true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6651 msg=1714 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=30726959 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=14022169 clear= true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6640 msg=1703 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=21041004 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6639 msg=1702 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1045392 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [durpublisher, publisher, guest]
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6528 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=20325696 clear= true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6531 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27648793
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6639 msg=1702 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1045392
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6641 msg=1704 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=16401078 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6531 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27648793 clear=true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6639 msg=1702 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1045392 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6642 msg=1705 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=3266284 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6531 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27648793 clear= true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6641 msg=1704 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=16401078
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6643 msg=1706 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=10054231 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6642 msg=1705 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=3266284
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6644 msg=1707 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1352498 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6641 msg=1704 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=16401078 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6638 msg=1701 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=10465479 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6642 msg=1705 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=3266284 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6644 msg=1707 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1352498
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6644 msg=1707 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1352498 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6643 msg=1706 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=10054231
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6643 msg=1706 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=10054231 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6645 msg=1708 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=15091836 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6645 msg=1708 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=15091836
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6646 msg=1709 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=18147176 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6645 msg=1708 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=15091836 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] run lock release, validateSoftReferenceDepth
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6646 msg=1709 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=18147176
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6652 msg=2468 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=13821921
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6646 msg=1709 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=18147176 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6647 msg=1710 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=23590218 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6647 msg=1710 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=23590218
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6647 msg=1710 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=23590218 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6640 msg=1703 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=21041004 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6652 msg=2468 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=13821921 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6652 msg=2468 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=13821921 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6648 msg=1711 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1629012 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6648 msg=1711 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1629012
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6648 msg=1711 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1629012 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6650 msg=1713 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=8908628 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6650 msg=1713 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=8908628
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6650 msg=1713 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=8908628 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6639 msg=1702 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1045392 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6649 msg=1712 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=31951808 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6649 msg=1712 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=31951808
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6649 msg=1712 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=31951808 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6651 msg=1714 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=30726959 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6651 msg=1714 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=30726959
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 6651 msg=1714 hard NOT_STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=30726959 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6528 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=20325696 clear= true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6528 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=20325696
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6528 msg=2427 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=20325696
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6531 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27648793 clear= true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=20325696 clear= true reset=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6641 msg=1704 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=16401078 transaction=null
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756 wasHard=true
2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6531 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27648793
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6631 msg=1695 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=33080756
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6652 msg=2468 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=13821921 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6531 msg=2428 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27648793
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6652 msg=2468 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=13821921
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=27648793 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.jms.asf.StdServerSessionPool] getting a server session
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6537 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=1359629
2004-04-01 14:31:10,828 TRACE [org.jboss.jms.asf.StdServerSessionPool] using server session: org.jboss.jms.asf.StdServerSession@54f169
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6530 msg=2428 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6537 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=1359629 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpyConnectionConsumer] SpyConnectionConsumer:QUEUE.testQueue Starting the ServerSession.
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=23099805 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6537 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=1359629 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.jms.asf.StdServerSession] starting invokes on server session
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6532 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=26335371
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6537 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=1359629 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6532 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=26335371 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6537 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=1359629
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6642 msg=1705 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=3266284 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1072
2004-04-01 14:31:10,828 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : receive
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6532 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=26335371 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6537 msg=2431 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=1359629
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:10,828 TRACE [org.jboss.jms.asf.StdServerSession] running...
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6532 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=26335371 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=1359629 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
2004-04-01 14:31:10,828 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpyXAResourceManager] Starting tx with new xid=-9223372036854774113
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6532 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=26335371
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpySession] Setting current tx org.jboss.mq.SpyTopicSession@5b55a9 xid=-9223372036854774113 previous: null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6532 msg=2429 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=26335371
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6529 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=3510804
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -1
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpyXAResourceManager] Ack'ing message xid=-9223372036854774113
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=26335371 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6529 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=3510804 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:4/0ad687b82472a8e4065fcee90572b2e8 subId=-2147483648
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6644 msg=1707 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1352498 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:guest)
;principal=null;roles=Roles(members:guest) for rolePrincipals [publisher, guest]
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:10,828 TRACE [org.jboss.jms.asf.StdServerSession] onMessage running (pool, session, xaSession, useLocalTX): , org.jboss.mq.SpyTopicSession@5b55a9, org.jboss.mq.SpyTopicSession@5b55a9, true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpyXAResource] Start xid=XidImpl [FormatId=257, GlobalId=mls-dev//163373, BranchQual=], flags=0
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6529 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=3510804 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6529 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=3510804 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpyXAResourceManager] Converting tx anonXid=-9223372036854774113, xid=XidImpl [FormatId=257, GlobalId=mls-dev//163373, BranchQual=]
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6534 msg=2430 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28109086
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6529 msg=2427 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=3510804
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6534 msg=2430 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28109086 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.SpySession] Setting current tx org.jboss.mq.SpyTopicSession@5b55a9 xid=XidImpl [FormatId=257, GlobalId=mls-dev//163373, BranchQual=] previous: -9223372036854774113
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6529 msg=2427 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=3510804
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6534 msg=2430 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28109086 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6645 msg=1708 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=15091836 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=3510804 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6533 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14188563
2004-04-01 14:31:10,828 TRACE [org.jboss.jms.asf.StdServerSession] Using optimized 1p commit to control TX.
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6534 msg=2430 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28109086 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.ejb.plugins.jms.JMSContainerInvoker] processing message: org.jboss.mq.SpyObjectMessage {
Header {
jmsDestination : QUEUE.testQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:21-108082626876547
jmsTimeStamp : 1080826268765
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropertiesReadWrite:false
msgReadOnly : true
producerClientId: ID:21
}
}
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6533 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14188563 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6533 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14188563 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6534 msg=2430 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28109086
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6533 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14188563 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6533 msg=2429 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14188563
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6533 msg=2429 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=14188563
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6643 msg=1706 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=10054231 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6534 msg=2430 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28109086
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=28109086 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] getMessage lock aquire 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6536 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=12220255
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=14188563 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire message 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6536 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=12220255 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6541 msg=2433 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27947434
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent lock aquire lrucache 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6536 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=12220255 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6541 msg=2433 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27947434 clear=true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] messageReferenceUsedEvent locks released 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360 wasHard=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6541 msg=2433 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27947434 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageReference] getMessage lock released 6632 msg=1696 hard STORED PERSISTENT queue=QUEUE.testQueue priority=4 hashCode=24894360
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6536 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=12220255 clear= true reset=true
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6647 msg=1710 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=23590218 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6648 msg=1711 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=1629012 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6646 msg=1709 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=18147176 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6649 msg=1712 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=31951808 transaction=null
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,828 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6650 msg=1713 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=8908628 transaction=null
2004-04-01 14:31:10,843 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 6651 msg=1714 hard STORED PERSISTENT queue=QUEUE.testQueue priority=1 hashCode=30726959 transaction=null
2004-04-01 14:31:10,843 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,843 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,843 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,843 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:10,843 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6536 msg=2431 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=12220255
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6541 msg=2433 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27947434 clear= true reset=true
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1076
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1073
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1074
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,015 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1075
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1078
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1079
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1077
2004-04-01 14:31:11,031 TRACE [org.jboss.jms.asf.StdServerSessionPool] getting a server session
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6536 msg=2431 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=12220255
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6541 msg=2433 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27947434
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1081
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1082
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1080
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1083
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1084
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closing sessions, ClientID=ID:1085
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.jms.asf.StdServerSessionPool] using server session: org.jboss.jms.asf.StdServerSession@17aaa0e
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=12220255 clear= true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6541 msg=2433 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=27947434
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.SpySession] Session closing.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.SpyConnectionConsumer] SpyConnectionConsumer:QUEUE.testQueue Starting the ServerSession.
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6538 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28359382
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock release message NOT IN CACHE hashCode=27947434 clear= true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Closed sessions
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
2004-04-01 14:31:11,031 TRACE [org.jboss.jms.asf.StdServerSession] starting invokes on server session
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6538 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28359382 clear=true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6539 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=28993973
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 DEBUG [org.jboss.mq.Connection] Notifiying the server of close
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Connection Initializing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : receive
2004-04-01 14:31:11,031 TRACE [org.jboss.jms.asf.StdServerSession] running...
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6538 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28359382 clear= true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire message 6539 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=28993973 clear=true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Getting the serverIL
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.SpyXAResourceManager] Starting tx with new xid=-9223372036854774112
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6538 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28359382 clear= true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock aquire lrucache 6539 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=28993973 clear= true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : connectionClosing
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] serverIL=org.jboss.mq.il.jvm.JVMServerIL@59c8b5
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -1
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.SpySession] Setting current tx org.jboss.mq.SpyTopicSession@2ee7e5 xid=-9223372036854774112 previous: null
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6538 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28359382
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageCache] remove lock release lrucache 6539 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=28993973 clear= true reset=true
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Stoping the ClientIL service
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Authenticating
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:4/0ad687b82472a8e4065fcee90572b2e8 subId=-2147483648
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.SpyXAResourceManager] Ack'ing message xid=-9223372036854774112
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageReference] clear lock relased 6538 msg=2432 hard REMOVED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=28359382
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.server.MessageReference] clear lock aquire 6539 msg=2432 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:1.-2147483648 priority=1 hashCode=28993973
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
2004-04-01 14:31:11,031 TRACE [org.jboss.mq.Connection] Disconnected from server
Actions
7. Re: Messages disappear - jboss 3.2.3

adrian.brock Apr 1, 2004 8:17 AM (in response to moppersmurf)

This looks like the cause of your problem:

2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805

The message is passing its TTL (time to live). Which is 10 seconds by the looks of it.

You might also try your test using 3.2.4RC1 which has a lot more TRACE
logging so you can see what is happening.

Regards,
Adrian
Actions
8. Re: Messages disappear - jboss 3.2.3

moppersmurf Apr 1, 2004 8:36 AM (in response to moppersmurf)

"adrian@jboss.org" wrote:
This looks like the cause of your problem:

2004-04-01 14:31:10,812 TRACE [org.jboss.mq.server.BasicQueue] message expired: 6530 msg=2428 hard NOT_STORED PERSISTENT queue=TOPIC.testTopic.ID:3.-2147483648 priority=1 hashCode=23099805

The message is passing its TTL (time to live). Which is 10 seconds by the looks of it.

You might also try your test using 3.2.4RC1 which has a lot more TRACE
logging so you can see what is happening.

Regards,
Adrian

But why does it expire and is it not handled by a MDB? There are al lot of MDB resources available.
Actions
9. Re: Messages disappear - jboss 3.2.3

moppersmurf Apr 2, 2004 2:53 AM (in response to moppersmurf)

I did some tests, one with a time-to-live of 20 seconds and one with a time-to-live of 120 seconds. When the time-to-live is 120 seconds all requests (approx. 1600 in 8 minutes) are handled by a MDB. But with 20 seconds approx 25% expire on the topic and are therfore never handled by a MDB.
I configured that 1000 MDBs can exist. This should be more than enough considering the fact that one request is handled by a MDB in 2 seconds.

Any idea why 25% never get handled by a MDB with a time-to-live of 20 seconds? is the JMS provider not capable of handling more than 3 messages sent to a topic? Or does it take some time for the MDBs to return to the pool?
Actions
10. Re: Messages disappear - jboss 3.2.3

moppersmurf Apr 5, 2004 3:17 AM (in response to moppersmurf)

"adrian@jboss.org" wrote:
You haven't posted your configuration that shows you have 1000 mdbs.

Most likely you have configured the pool and not the most important part
which is the serversession pool (default size 15).
See the FAQ topic for some examples.

<invoker-proxy-binding>
message-driven-bean
<invoker-mbean>default</invoker-mbean>
<proxy-factory>org.jboss.ejb.plugins.jms.JMSContainerInvoker</proxy-factory>
<proxy-factory-config>
DefaultJMSProvider
StdJMSPool
1000
1
...
and

<container-configuration>
<container-name>Standard Message Driven Bean</container-name>
...
<container-pool-conf>
1000
</container-pool-conf>
...

"adrian@jboss.org" wrote:

Even so, it depends what your MDB does. You only have so much cpu.
If it takes .5 seconds of cpu to process a request that is 20 requests in 10 seconds
for one cpu (and I assume nothing else is using cpu).

Regards,
Adrian

The CPU usage at the time of testing is approx. 15-25%.
Actions
11. Re: Messages disappear - jboss 3.2.3

adrian.brock Apr 5, 2004 4:52 AM (in response to moppersmurf)

So show me where it is spending the time.

We could be here until the end of the world trying to guess what is happening.

If you don't have a profiler, a quick and dirty is to take a couple of thread dumps
and look at the stacktraces. e.g. is it stuck in db operations, entity beans locks, etc.?

Regards,
Adrian
Actions

Go to original post