users@glassfish.java.net

Re: JMS BrokerException

From: Amy Kang <amy.kang_at_oracle.com>
Date: Fri, 19 Nov 2010 20:28:28 -0800

  On 11/19/2010 04:55 AM, saikiranp wrote:
> Hi Amy,
> I went through the code as saw that the api from where i get TTL return
> 300 sec as value.

Thanks for let us know. The default time-to-live for a message in
GlassFish MQ is 0.

amy

>
>
> Thanks for your help.
>
> Regards
> Saikiran.P
>
> saikiranp wrote:
>> We are sending all the messages with 0 to only one destination.
>>
>> Still the messages are getting expired.
>>
>> I have enabled the dead message queue logs.. please see the logs below..
>> all the messages are getting expired for 300,000 milli seconds.. i.e
>> exactly for 5 min. Is there some default TTL used by broker to expired
>> the messages from the queues?
>>
>> [15/Nov/2010:08:08:12 CET] [B1147]: Message
>> 11492269-192.168.0.4(b7:bf:3b:6:a:a2)-49414-1289804553618 from destination
>> Q:ServiceQueue has been placed on the DMQ because [B0053]: Message on
>> destination Q:ServiceQueue Expired: expiration time 1289804853618,
>> arrival time 1289804591757, JMSTimestamp 1289804553618
>> [15/Nov/2010:08:08:12 CET] [B1147]: Message
>> 11492270-192.168.0.4(b7:bf:3b:6:a:a2)-49414-1289804553698 from destination
>> Q:ServiceQueue has been placed on the DMQ because [B0053]: Message on
>> destination Q:ServiceQueue Expired: expiration time 1289804853697,
>> arrival time 1289804591812, JMSTimestamp 1289804553698
>> [15/Nov/2010:08:08:12 CET] [B1147]: Message
>> 11492271-192.168.0.4(b7:bf:3b:6:a:a2)-49414-1289804553705 from destination
>> Q:ServiceQueue has been placed on the DMQ because [B0053]: Message on
>> destination Q:ServiceQueue Expired: expiration time 1289804853705,
>> arrival time 1289804591762, JMSTimestamp 1289804553705
>>
>> Regards
>> Saikiran
>>
>> Amy Kang-3 wrote:
>>> >i am setting the time to live as 0( Not -1).
>>>
>>> Then the broker would not expire the message. Do you send some
>>> messages with non-zero 'time to live' and some messages with 0 'time to
>>> live' to the same destination or to difference destinations ?
>>>
>>> amy
>>>
>>> On 11/16/10 05:52, Nigel Deakin wrote:
>>>> Try this:
>>>>
>>>> -vmargs -Xms256m -vmargs -Xmx1024m
>>>>
>>>> No quotes.
>>>>
>>>> Nigel
>>>>
>>>> saikiranp wrote, on 16/11/2010 05:55:
>>>>> Hi Amy,
>>>>> Sorry, i am setting the time to live as 0( Not -1).
>>>>>
>>>>> Could u send me the exact command to increase the heap levels for
>>>>> imqbroker.
>>>>>
>>>>> I tried to set using<cluster-instance-name>.ms-service.start-args =
>>>>> "-vmargs "-Xms256m -Xmx1024m"". but it is not working..
>>>>>
>>>>> Regards
>>>>> Saikiran
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> Amy Kang-3 wrote:
>>>>>> On 11/15/10 04:26, saikiranp wrote:
>>>>>>> Hi Amy,
>>>>>>> What could be the reason for message expiration?
>>>>>>>
>>>>>>>
>>>>>> the JMS client that sent the message has specified non-zero expiration
>>>>>> when sending the message.
>>>>>>> We also set time to live for all these messages as -1 ( never
>>>>>>> expire).
>>>>>>> Still could not understand why the messages are getting expired?
>>>>>>>
>>>>>> 0 is never expire according to the JMS specification (section 3.4.9
>>>>>> JMSExpiration). Please also see JMS javadoc
>>>>>> http://download.oracle.com/javaee/5/api/javax/jms/MessageProducer.html#setTimeToLive(long)
>>>>>>
>>>>>>
>>>>>> amy
>>>>>>> Regards
>>>>>>> Saikiran
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Amy Kang-3 wrote:
>>>>>>>
>>>>>>>> Saikiran,
>>>>>>>>
>>>>>>>>
>>>>>>>> On 11/12/2010 04:11 AM, saikiranp wrote:
>>>>>>>>
>>>>>>>>> Hi Amy,
>>>>>>>>>
>>>>>>>>> We are actually using REJECT_NEWEST.
>>>>>>>>>
>>>>>>>>> So the messages expired are not because the max limit of the
>>>>>>>>> queue
>>>>>>>>> reached and then the old ones are getting removed. I could also see
>>>>>>>>> that
>>>>>>>>> the
>>>>>>>>> metrics of the queue shows that it has not reached max limit.
>>>>>>>>>
>>>>>>>>> But we can see from the imq logs that the messages are
>>>>>>>>> expired. May
>>>>>>>>> be
>>>>>>>>> because of the some other reason and after that i see these JMS
>>>>>>>>> rollback
>>>>>>>>> exceptions. please see the attached log for more information.
>>>>>>>>>
>>>>>>>>> http://old.nabble.com/file/p30198742/log.txt
>>>>>>>>>
>>>>>>>> [10/Nov/2010:00:18:55 CET] [B1140]: Expired 645 messages from
>>>>>>>> destination
>>>>>>>> BcsVoicePhysicalChargingServiceQueue [Queue]
>>>>>>>> [10/Nov/2010:00:19:55 CET] [B1140]: Expired 1200 messages from
>>>>>>>> destination
>>>>>>>> BcsVoicePhysicalChargingServiceQueue [Queue]
>>>>>>>> [10/Nov/2010:00:19:56 CET] WARNING [B3229]: Transaction
>>>>>>>> acknowledgement
>>>>>>>> [3675199-192.168.0.4(91:2c:61:56:e2:df)-59265-1289344417629,
>>>>>>>> [consumer:2430022061644300032, type=NONE]]TUID=2430022071232245504
>>>>>>>> processing failed: [B1290]: Transaction acknowledgement could not be
>>>>>>>> processed because message
>>>>>>>> 3675199-192.168.0.4(91:2c:61:56:e2:df)-59265-1289344417629[[consumer:2430022061644300032,
>>>>>>>>
>>>>>>>> type=NONE]:[consumer:0,
>>>>>>>> type=CLIENT_ACKNOWLEDGE]]TUID=2430022071232245504
>>>>>>>> reference is gone :
>>>>>>>> com.sun.messaging.jmq.jmsserver.util.BrokerException: [B1290]:
>>>>>>>> Transaction
>>>>>>>> acknowledgement could not be processed because message
>>>>>>>> 3675199-192.168.0.4(91:2c:61:56:e2:df)-59265-1289344417629[[consumer:2430022061644300032,
>>>>>>>>
>>>>>>>> type=NONE]:[consumer:0,
>>>>>>>> type=CLIENT_ACKNOWLEDGE]]TUID=2430022071232245504
>>>>>>>> reference is gone
>>>>>>>> ......
>>>>>>>>
>>>>>>>> The above warning log message would cause the transaction rollback
>>>>>>>> on
>>>>>>>> application side. Since the warning messages came right after the
>>>>>>>> "Expired .. messages .." log messages, it's very likely that the
>>>>>>>> rollback
>>>>>>>> was due to removed expired messages that have been delivered to
>>>>>>>> client.
>>>>>>>> In 4.5 (>= build21), message expiration handling has been
>>>>>>>> improvement.
>>>>>>>> Please see bug fixes 6761759, 6186088.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>> The sailfin version we are using is "Sun GlassFish
>>>>>>>>> Communications
>>>>>>>>> Server
>>>>>>>>> 1.5 ((v2.1 Patch12)(9.1_02 Patch18)) (build b01-p12)"
>>>>>>>>>
>>>>>>>>> JMS service type is "LOCAL".
>>>>>>>>>
>>>>>>>>> As the type is set as LOCAL, imqbroker will be started by
>>>>>>>>> sailfin. I
>>>>>>>>> would
>>>>>>>>> also like to know how to change the vmargs for broker.
>>>>>>>>>
>>>>>>>> You can use the start-args attribute of the jms-service element,
>>>>>>>> please
>>>>>>>> see
>>>>>>>> http://docs.sun.com/app/docs/doc/820-7695/beaof?l=en&a=view
>>>>>>>>
>>>>>>>> amy
>>>>>>>>
>>>>>>>>
>>>>>>>>> Saikiran
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Amy Kang-3 wrote:
>>>>>>>>>
>>>>>>>>>> A message sent to client can be removed by broker under
>>>>>>>>>> conditions,
>>>>>>>>>> e.g. message expired, destination limit reached with
>>>>>>>>>> REMOVE_OLDEST
>>>>>>>>>> behavior, remote message rerouted due to consumer closing ..
>>>>>>>>>> When
>>>>>>>>>> that
>>>>>>>>>> happens, the following JMSException simply instructs the
>>>>>>>>>> transaction
>>>>>>>>>> manager to rollback the transaction, which is expected. Please
>>>>>>>>>> check
>>>>>>>>>> the broker log to see any log message indicates reason for the
>>>>>>>>>> message
>>>>>>>>>> removal.
>>>>>>>>>>
>>>>>>>>>> The broker exception can also occur if the client side was
>>>>>>>>>> concurrently
>>>>>>>>>> using a XA session. Which GlassFish version/build# are you using
>>>>>>>>>> ?
>>>>>>>>>> What is the version shown at beginning of MQ broker log ? Are you
>>>>>>>>>> using
>>>>>>>>>> GlassFish or MQ cluster or single instance ?
>>>>>>>>>>
>>>>>>>>>> amy
>>>>>>>>>>
>>>>>>>>>> On 08/10/2010 04:32 AM, saikiranp wrote:
>>>>>>>>>>
>>>>>>>>>>> We have been getting JMS exceptions and we are in the process of
>>>>>>>>>>> finding
>>>>>>>>>>> the
>>>>>>>>>>> root cause for this issue.
>>>>>>>>>>>
>>>>>>>>>>> From the server.log, we observed that there were logs
>>>>>>>>>>> regarding the
>>>>>>>>>>> MDB
>>>>>>>>>>> invocation errors.
>>>>>>>>>>>
>>>>>>>>>>> [#|2010-07-23T01:54:41.731+0200|INFO|sun-glassfish-comms-server1.5|javax.enterprise.system.container.ejb.mdb|_ThreadID=385;_ThreadName
>>>>>>>>>>>
>>>>>>>>>>> =p: thread-pool-1; w:
>>>>>>>>>>> 60;backend-ear-0.0.0.1-SNAPSHOT:MessageProcessor;javax.ejb.EJBException:
>>>>>>>>>>>
>>>>>>>>>>> Transaction aborted; nested exception
>>>>>>>>>>> is: javax.transaction.RollbackException;|MDB00037:
>>>>>>>>>>> [backend-ear-0.0.0.1-SNAPSHOT:MessageProcessor]: Message-driven
>>>>>>>>>>> bean
>>>>>>>>>>> invocation ex
>>>>>>>>>>> ception: [javax.ejb.EJBException: Transaction aborted; nested
>>>>>>>>>>> exception
>>>>>>>>>>> is:
>>>>>>>>>>> javax.transaction.RollbackException]|#]
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> We suspected that the broker was removing the messages even
>>>>>>>>>>> before
>>>>>>>>>>> the
>>>>>>>>>>> acknowledgement is received from the MDB due to the TTL being
>>>>>>>>>>> set for
>>>>>>>>>>> some
>>>>>>>>>>> types of messages. Hence, we changed the TTL value to 0. However,
>>>>>>>>>>> even
>>>>>>>>>>> after
>>>>>>>>>>> making the TTL to 0, we still see that the exceptions are still
>>>>>>>>>>> being
>>>>>>>>>>> thrown
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> [#|2010-08-05T11:10:34.136+0200|WARNING|sun-glassfish-comms-server1.5|javax.jms|_ThreadID=435;_ThreadName=p:
>>>>>>>>>>>
>>>>>>>>>>> thread-pool-1; w:
>>>>>>>>>>> 109;_RequestID=c71cd362-db29-413b-bcd0-ffeb7a864865;|[I500]:
>>>>>>>>>>> Caught
>>>>>>>>>>> JVM
>>>>>>>>>>> Exception: com.sun.messaging.jms.JMSException:
>>>>>>>>>>> [ACKNOWLEDGE_REPLY(25)]
>>>>>>>>>>> [C4036]: A broker error occurred. :[409] [B1290]: Transaction
>>>>>>>>>>> acknowledgement could not be processed because message
>>>>>>>>>>> 2720528-192.168.0.4(c7:69:53:86:9e:d4)-59781-1280998929518[[consumer:2274927222597296128,
>>>>>>>>>>>
>>>>>>>>>>> type=NONE]:[consumer:0,
>>>>>>>>>>> type=CLIENT_ACKNOWLEDGE]]TUID=2274927222650419200
>>>>>>>>>>> reference is gone user=guest, broker=localhost:37676(43191)|#]
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> [#|2010-08-05T11:10:34.136+0200|WARNING|sun-glassfish-comms-server1.5|javax.enterprise.system.stream.err|_ThreadID=435;_ThreadName=p:
>>>>>>>>>>>
>>>>>>>>>>> thread-pool-1; w:
>>>>>>>>>>> 109;_RequestID=c71cd362-db29-413b-bcd0-ffeb7a864865;|
>>>>>>>>>>>
>>>>>>>>>>> MQRA:OMR:run:JMSException on message acknowledgement:Rolling
>>>>>>>>>>> back if
>>>>>>>>>>> in
>>>>>>>>>>> txn|#]
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> [#|2010-08-05T11:10:34.137+0200|WARNING|sun-glassfish-comms-server1.5|javax.enterprise.system.stream.err|_ThreadID=435;_ThreadName=p:
>>>>>>>>>>>
>>>>>>>>>>> thread-pool-1; w:
>>>>>>>>>>> 109;_RequestID=c71cd362-db29-413b-bcd0-ffeb7a864865;|
>>>>>>>>>>>
>>>>>>>>>>> com.sun.messaging.jms.JMSException: [ACKNOWLEDGE_REPLY(25)]
>>>>>>>>>>> [C4036]:
>>>>>>>>>>> A
>>>>>>>>>>> broker error occurred. :[409] [B1290]: Transaction
>>>>>>>>>>> acknowledgement
>>>>>>>>>>> could
>>>>>>>>>>> not
>>>>>>>>>>> be processed because message
>>>>>>>>>>> 2720528-192.168.0.4(c7:69:53:86:9e:d4)-59781-1280998929518[[consumer:2274927222597296128,
>>>>>>>>>>>
>>>>>>>>>>> type=NONE]:[consumer:0,
>>>>>>>>>>> type=CLIENT_ACKNOWLEDGE]]TUID=2274927222650419200
>>>>>>>>>>> reference is gone user=guest, broker=localhost:37676(43191)
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.messaging.jmq.jmsclient.ProtocolHandler.throwServerErrorException(ProtocolHandler.java:4019)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.messaging.jmq.jmsclient.ProtocolHandler.acknowledge(ProtocolHandler.java:2607)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.messaging.jmq.jmsclient.SessionImpl.doAcknowledge(SessionImpl.java:1442)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.messaging.jmq.jmsclient.SessionImpl.acknowledgeFromRAEndpoint(SessionImpl.java:1097)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:267)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:76)
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> Caused by: com.sun.messaging.jms.JMSException:
>>>>>>>>>>> [ACKNOWLEDGE_REPLY(25)]
>>>>>>>>>>> [C4036]: A broker error occurred. :[409] [B1290]: Transaction
>>>>>>>>>>> acknowledgement could not be processed because message
>>>>>>>>>>> 2720528-192.168.0.4(c7:69:53:86:9e:d4)-59781-1280998929518[[consumer:2274927222597296128,
>>>>>>>>>>>
>>>>>>>>>>> type=NONE]:[consumer:0,
>>>>>>>>>>> type=CLIENT_ACKNOWLEDGE]]TUID=2274927222650419200
>>>>>>>>>>> reference is gone user=guest, broker=localhost:37676(43191)
>>>>>>>>>>>
>>>>>>>>>>> at
>>>>>>>>>>> com.sun.messaging.jmq.jmsclient.ProtocolHandler.throwServerErrorException(ProtocolHandler.java:4003)
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> ... 6 more
>>>>>>>>>>>
>>>>>>>>>>> |#]
>>>>>>>>>>>
>>>>>>>>>>> Can anybody give me some information on the root cause of this
>>>>>>>>>>> issue?
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>
>>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
>>>>>>>>>> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>> ---------------------------------------------------------------------
>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
>>>>>>>> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
>>>>>> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>>>>>>
>>>>>>
>>>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
>>>> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
>>> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>>>
>>>
>>>
>>