12 Replies Latest reply on May 3, 2005 11:50 PM by jcstaff

    can't get JMS to rollback send using JmsXA

    jcstaff

      I cannot get my JMS sends to get rolled back as a part of a session bean setRollbackOnly() or EJBException. I am using:
      * transaction required on the session bean
      * java:/JmsXA connection factory
      * setting local transactions=false on the session
      * trying SessionContext.setRollbackOnly()
      * trying throw EJBException

      No matter what I try, my JMS subscribers to the topic all see the message that was published.

      Any ideas on what I may be missing?

      //from ejb-jar.xml
      <container-transaction>
       <method>
       <ejb-name>PublisherEJB</ejb-name>
       <method-name>*</method-name>
       </method>
       <trans-attribute>Required</trans-attribute>
      </container-transaction>
      
      //from jboss.xml
      <resource-ref>
       <res-ref-name>jms/myConnectionFactory</res-ref-name>
       <jndi-name>java:/JmsXA</jndi-name>
      </resource-ref>
      
      //from ejbCreate()
       ConnectionFactory cFactory = (ConnectionFactory)
       jndi.lookup("java:comp/env/jms/myConnectionFactory");
       Connection connection = cFactory.createConnection();
       session_ = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
      
      //from session bean
      TextMessage msg = session_.createTextMessage();
      msg.setText(text);
      producer_.send(msg);
      ctx_.setRollbackOnly();
      
      //from session bean (another method)
      TextMessage msg = session_.createTextMessage();
      msg.setText(text);
      producer_.send(msg);
      throw new EJBException("trying to rollback transaction");
      


        • 1. 3857526
          jcstaff

          This is because Oracle JDBC driver is not JDBC conformant. Or they want to teach us all how to live. They believe, that using statement.setInputStream(), like jdbc2.PersistenceManager does, is not efficient enough to use, so they limited it to 4kb (actually this is because they passing BLOB as a RAW datatype, because for smaller lengths it is more efficient to include it in row data, which is limited since beginning of time in Oracle to 4k). For larger lengths they force us to use their non standard and crappy oracle.sql.BLOB extension.

          So i just written my own patched version of jdbc2.PersistenceManager to use this Oracle's BLOBs extension, which is available here:
          http://core.swdfactory.com/~oleg/jbossmq-orapm.zip

          Please keep in mind - it works only with oracle database using Oracle JDBC drivers, developed by Oracle.

          You can use this freely, but on your own risk. 8-)

          • 2. Re: can't get JMS to rollback send using JmsXA
            genman


            I thought if it was transacted, you have to use "true" when creating QueueSession:

            session_ = connection.createSession(true, 0);

            • 3. Re: can't get JMS to rollback send using JmsXA
              jcstaff

              From what I have come to know "true" means use internal transactions, which would require one to use manual calls to commit()/rollback() on the session. "false" either means none at all (similar to JDBC autocommit=false) when no JTA is active or part of the JTA when using an XAConnection factory.

              I'm still having issues with this and would either like to find out that I have it setup wrong or that the HSQL setup from the factory does not support the XA transaction that I'm trying to demonstrate.

              jim

              • 4. Re: can't get JMS to rollback send using JmsXA

                Show the trace logging so we can see what is happening.
                org.jboss.ejb.plugins.TxInterceptorCMT or
                org.jboss.resource
                org.jboss.tm
                would also be useful so we can see the transaction demarcation

                • 5. Re: can't get JMS to rollback send using JmsXA
                  jcstaff

                  I want to make sure I'm doing what you intend to get you the information you've requested.

                  * "show trace logging". I'm assuming that means go into conf/log4j.xml and add the following lines:

                  <category name="org.jboss.ejb.plugins.TxInterceptorCMT">
                   <priority value="DEBUG"/>
                  </category>
                  <category name="org.jboss.resource">
                   <priority value="DEBUG"/>
                  </category>
                  <category name="org.jboss.tm">
                   <priority value="DEBUG"/>
                  </category>
                  


                  I also tried TRACE (versus DEBUG above), but the server.log seemed to contain no mention of the above classes. Can you provide some specifics to get what you need and I'll gladly track them down.

                  thanks,
                  jim

                  2004-12-17 16:03:19,993 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] >>> publishThrow
                  2004-12-17 16:03:19,993 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] session getTransacted=false
                  2004-12-17 16:03:19,993 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] tx rollbackOnly=false
                  2004-12-17 16:03:20,003 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] publishing message:three
                  2004-12-17 16:03:20,003 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] message published:three
                  2004-12-17 16:03:20,003 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] tx rollbackOnly=false
                  2004-12-17 16:03:20,013 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] throwing EJBException
                  2004-12-17 16:03:20,013 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] tx rollbackOnly=false
                  2004-12-17 16:03:20,013 ERROR [org.jboss.ejb.plugins.LogInterceptor] EJBException in method: public abstract void corej2ee.examples.jta.ejb.PublisherRemote.publishThrow(java.lang.S
                  tring) throws java.rmi.RemoteException:
                  javax.ejb.EJBException: error:javax.ejb.EJBException: trying to rollback transaction
                   at corej2ee.examples.jta.ejb.PublisherEJB.publishThrow(PublisherEJB.java:70)
                  ...
                  org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:279)
                   at java.lang.Thread.run(Thread.java:534)
                  2004-12-17 16:03:20,343 DEBUG [org.jboss.mq.il.uil2.SocketManager] End ReadTask.run
                  2004-12-17 16:03:20,343 DEBUG [org.jboss.mq.il.uil2.SocketManager] End WriteTask.run
                  


                  • 6. Re: can't get JMS to rollback send using JmsXA

                    TRACE is what is required. See the examples in READ THIS FIRST.
                    Also make sure you are not filtering the level on the appender.

                    I won't need your DEBUG logging.

                    • 7. Re: can't get JMS to rollback send using JmsXA
                      jcstaff

                      This looks to be more of what you were after. This is the result of the session EJB throwing EJBException after publishing the JMS message. ...

                      thanks for taking a look at it.

                      2004-12-17 17:21:01,465 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] popped object: org.jboss.resource.connectionmanager.CachedConnectionManager$KeyConnecti
                      onAssociation@e222eb
                      2004-12-17 17:21:01,465 TRACE [org.jboss.tm.TransactionImpl] setRollbackOnly(): Entered, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=, localId=22] status
                      =STATUS_ACTIVE
                      2004-12-17 17:21:01,465 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] TxInterceptorCMT: In finally
                      2004-12-17 17:21:01,465 TRACE [org.jboss.tm.TransactionImpl] rollback(): Entered, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=, localId=22] status=STATUS
                      _MARKED_ROLLBACK
                      2004-12-17 17:21:01,465 TRACE [org.jboss.tm.TxManager] suspended tx: TransactionImpl:XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=, localId=22]
                      2004-12-17 17:21:01,465 TRACE [org.jboss.tm.TxManager] tx timeout is now: 300s
                      2004-12-17 17:21:01,465 ERROR [org.jboss.ejb.plugins.LogInterceptor] EJBException in method: public abstract void corej2ee.examples.jta.ejb.PublisherRemote.publishThrow(java.lang.S
                      tring) throws java.rmi.RemoteException:
                      javax.ejb.EJBException: error:javax.ejb.EJBException: trying to rollback transaction
                       at corej2ee.examples.jta.ejb.PublisherEJB.publishThrow(PublisherEJB.java:70)
                      


                      • 8. Re: can't get JMS to rollback send using JmsXA

                        I see the transaction rolling back:


                        2004-12-17 17:21:01,465 TRACE [org.jboss.tm.TransactionImpl] rollback(): Entered, tx=TransactionImpl
                        :XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=, localId=22] status=STATUS
                        _MARKED_ROLLBACK


                        I don't see any
                        org.jboss.mq
                        org.jboss.resource
                        logging in response to this, which tells me that either you haven't enabled that logging
                        or the jms resource was never enlisted in the transaction being rolled back.

                        • 9. Re: can't get JMS to rollback send using JmsXA
                          jcstaff

                          Sorry fot the omission on org.jboss.mq. The following trace appears to have the mq trace messages from the time the session bean publishes the message, thru when the client begins to receive it.

                          thanks,

                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.SpyMessageProducer] Sending message SpyMessageProducer@27473621[ dest=TOPIC.corej2ee.jms.Topic1 delivery=persist pri
                          ority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@17988685[tx=true txid=null XA RUNNING connection=Connection@14459885[token=ConnectionTok
                          en:ID:2/04cb240d21712f09ef88dae7f8f79de7 rcvstate=STOPPED]]]
                          SpyTextMessage {
                          Header {
                           jmsDestination : TOPIC.corej2ee.jms.Topic1
                           jmsDeliveryMode : 2
                           jmsExpiration : 0
                           jmsPriority : 4
                           jmsMessageID : ID:2-11035696626603
                           jmsTimeStamp : 1103569662660
                           jmsCorrelationID: null
                           jmsReplyTo : null
                           jmsType : null
                           jmsRedelivered : false
                           jmsProperties : {}
                           jmsPropReadWrite: true
                           msgReadOnly : false
                           producerClientId: ID:2
                          }
                          Body {
                           text :three
                          }
                          }
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.SpySession] Adding message to transaction ID:2-11035696626603 SpySession@17988685[tx=true txid=null XA RUNNING conne
                          ction=Connection@14459885[token=ConnectionToken:ID:2/04cb240d21712f09ef88dae7f8f79de7 rcvstate=STOPPED]]
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.SpyXAResourceManager] No Xid, sending message to server ID:2-11035696626603
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.Connection] SendToServer message=ID:2-11035696626603 Connection@14459885[token=ConnectionToken:ID:2/04cb240d21712f09
                          ef88dae7f8f79de7 rcvstate=STOPPED]
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : SpyTextMessage {
                          Header {
                           jmsDestination : TOPIC.corej2ee.jms.Topic1
                           jmsDeliveryMode : 2
                           jmsExpiration : 0
                           jmsPriority : 4
                           jmsMessageID : ID:2-11035696626603
                           jmsTimeStamp : 1103569662660
                           jmsCorrelationID: null
                           jmsReplyTo : null
                           jmsType : null
                           jmsRedelivered : false
                           jmsProperties : {}
                           jmsPropReadWrite: true
                           msgReadOnly : false
                           producerClientId: ID:2
                          }
                          Body {
                           text :three
                          }
                          }
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
                           Principal: guest
                           Principal: Roles(members:j2ee,guest,john)
                          ;principal=guest;roles=Roles(members:j2ee,guest,john) for rolePrincipals [guest]
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.server.BasicQueue] addMessage 45 msg=2 hard NOT_STORED PERSISTENT queue=TOPIC.corej2ee.jms.Topic1.ID:1.-2147483648 p
                          riority=4 lateClone=false hashCode=10735167 null org.jboss.mq.server.ExclusiveQueue@85a863{id=TOPIC.corej2ee.jms.Topic1.ID:1.-2147483648}
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.server.BasicQueue] internalAddMessage 45 msg=2 hard NOT_STORED PERSISTENT queue=TOPIC.corej2ee.jms.Topic1.ID:1.-214
                          7483648 priority=4 lateClone=false hashCode=10735167 org.jboss.mq.server.ExclusiveQueue@85a863{id=TOPIC.corej2ee.jms.Topic1.ID:1.-2147483648}
                          2004-12-20 14:07:42,660 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
                          2004-12-20 14:07:42,660 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] message published:three
                          2004-12-20 14:07:42,660 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] tx rollbackOnly=false
                          2004-12-20 14:07:42,660 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] throwing EJBException
                          2004-12-20 14:07:42,660 DEBUG [corej2ee.examples.jta.ejb.PublisherEJB] tx rollbackOnly=false
                          2004-12-20 14:07:42,660 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] popped object: org.jboss.resource.connectionmanager.CachedConnectio
                          nManager$KeyConnectionAssociation@64dfeb
                          2004-12-20 14:07:42,660 TRACE [org.jboss.tm.TransactionImpl] setRollbackOnly(): Entered, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=
                          , localId=22] status=STATUS_ACTIVE
                          2004-12-20 14:07:42,660 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] TxInterceptorCMT: In finally
                          2004-12-20 14:07:42,660 TRACE [org.jboss.tm.TransactionImpl] rollback(): Entered, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=, local
                          Id=22] status=STATUS_MARKED_ROLLBACK
                          2004-12-20 14:07:42,660 TRACE [org.jboss.tm.TxManager] suspended tx: TransactionImpl:XidImpl[FormatId=257, GlobalId=BLITZ/22, BranchQual=, localId=22]
                          2004-12-20 14:07:42,660 TRACE [org.jboss.tm.TxManager] tx timeout is now: 300s
                          2004-12-20 14:07:42,660 ERROR [org.jboss.ejb.plugins.LogInterceptor] EJBException in method: public abstract void corej2ee.examples.jta.ejb.PublisherRemote.publ
                          ishThrow(java.lang.String) throws java.rmi.RemoteException:
                          javax.ejb.EJBException: error:javax.ejb.EJBException: trying to rollback transaction
                          ...
                          2004-12-20 14:07:42,670 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.AcknowledgementRequestMsg24411663[msgT
                          ype: m_acknowledge, msgID: 10, error: null]
                          2004-12-20 14:07:42,670 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 1
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_receive, msgID: 11
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.ReceiveMsg22302276[msgType: m_receive, msgID: 11, err
                          or: null]
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 13
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : receive
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1000
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on ConnectionToken:ID:1/ffeeba66b95db477116cbaa7c7903
                          dd9 subId=-2147483648
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
                           Principal: guest
                           Principal: Roles(members:j2ee,guest,john)
                          ;principal=null;roles=Roles(members:j2ee,guest,john) for rolePrincipals [guest]
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.server.BasicQueue] receive Subscription[subId=-2147483648connection=ConnectionToken:ID:1/ffeeba66b95db477116cbaa7c79
                          03dd9 destination=TOPIC.corej2ee.jms.Topic1 messageSelector=null Local Create] wait=true org.jboss.mq.server.ExclusiveQueue@85a863{id=TOPIC.corej2ee.jms.Topic1.
                          ID:1.-2147483648}
                          2004-12-20 14:07:42,720 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
                          


                          • 10. Re: can't get JMS to rollback send using JmsXA

                             


                            2004-12-20 14:07:42,660 TRACE [org.jboss.mq.SpyXAResourceManager] No Xid, sending message to server
                            ID:2-11035696626603


                            It's not enlisted in the transaction.

                            • 11. Re: can't get JMS to rollback send using JmsXA

                              And of course the answer is obvious:


                              //from ejbCreate()
                              ConnectionFactory cFactory = (ConnectionFactory)
                              jndi.lookup("java:comp/env/jms/myConnectionFactory");
                              Connection connection = cFactory.createConnection();
                              session_ = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);


                              You are doing it wrong.

                              See my countless other posts about the correct usage of the connection pool
                              and why allocating a connection per bean doesn't scale (which you need unshared on the resource-ref to enable anyway).



                              • 12. Re: can't get JMS to rollback send using JmsXA
                                jcstaff

                                Its taken me a while to get back to this test and try your recommendations. I agree that the test code was not conserving resources the way it was written, but I did not give thought to the fact that the session and publisher was being created in a transaction and the publish was created in another transaction. I have re-arranged to java code within the bean and now derive the expected results; the JMS publish now gets rolled back with the JDBC/TX rollback.

                                ejbCreate() {
                                 //just lookup TopicConnectionFactory and Topic
                                
                                business method() {
                                 //cFactory.createConnection()
                                 //connection.createSession()
                                 //session.createPublisher()
                                 //session.createMessage()
                                 //publisher.publish(msg)
                                 //call entity bean which sets rollbackOnly
                                 //close publisherm session, and connection
                                


                                The setting of Shared versus Unshared in the resource-ref had no noticeable impact on the transaction behavior. Although your comments there may have been targeted towards conserving resources.

                                Thanks for the sanity check.
                                jim