9 Replies Latest reply on Jul 15, 2009 4:48 AM by gaohoward

    Messaging 1.4.0 SP3 with JBoss AS 4.2.3

    dbarkats

      Hi,

      I am using JBoss messaging 1.4.0 SP3 with JBoss AS 4.2.3.GA, with JBoss remoting 2.2.2 SP8.
      I have 6 clients who are sending message to queue and 4 clients who are receive message from Topic.

      on overload I have disconnection problem between subscriber (non-durable) and Topic. No problem with queues producer.

      Here is a stack trace on server:

      2008-08-28 21:39:04,466 ERROR [org.jboss.remoting.callback.ServerInvokerCallbackHandler] Error handling callback
      java.rmi.MarshalException: Failed to communicate. Problem during marshalling/unmarshalling; nested exception is:
      java.io.IOException: Connection reset
      at org.jboss.remoting.transport.socket.SocketClientInvoker.handleException(SocketClientInvoker.java:127)
      at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:689)
      at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:418)
      at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
      at org.jboss.remoting.Client.invoke(Client.java:1634)
      at org.jboss.remoting.Client.invoke(Client.java:548)
      at org.jboss.remoting.Client.invokeOneway(Client.java:598)
      at org.jboss.remoting.callback.ServerInvokerCallbackHandler.handleCallback(ServerInvokerCallbackHandler.java:826)
      .............

      Stack trace on Topic Client:

      1. Failure on underlying remoting connection

      javax.jms.JMSException: Failure on underlying remoting connection

      at org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:102)



      2. ???

      javax.jms.IllegalStateException: The object is closed



      3. MessagingNetworkFailureException

      org.jboss.jms.exception.MessagingNetworkFailureException

      at org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:113)

      Caused by: org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://192.168.101.11:4457/?JBM_clientMaxPoolSize=1000&clientLeasePeriod=10000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat]

      Caused by: java.net.ConnectException: Connection refused



      4. CommunicationException Receive timed out

      javax.naming.CommunicationException: Receive timed out [Root exception is java.net.SocketTimeoutException: Receive timed out]
      at org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:113)

      Caused by: java.net.SocketTimeoutException: Receive timed out


      Thank you for your help

        • 1. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3
          dbarkats

          Does anyone can help me on this problem

          THANK U

          • 2. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3
            dbarkats

            By changing TCP configuration on the server we have not yet this error but i want to understand.

            • 3. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3
              dbarkats

              The problem is back we have already this kind of deconnection

              • 4. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3

                facing exactly the same problem. we are using JBoss 4.2.3 GA with JBM 1.4. Do any one have solution for this?

                Assuming this could be because of network issue, we changed the JBoss server bind address to loop back address, but still got the same error, showing,

                2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[25724e, bisocket://10.1.150.170:2050639998] disconnecting ...

                2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ClientSocketWrapper[Socket[addr=/127.0.0.1,port=4235,localport=56656].1440636] closing

                2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[ab474q-8irr1u-fx4e2z0n-1-fx4e2ze3-4+ab474q-8irr1u-fx4e2z0n-1-fx4e2zg9-9] shut down

                Its quite urgent, can any one pls help?

                • 5. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3
                  gaohoward

                  Please give exact version of JBM. also the full stack trace may help better understanding your issue. Thanks!

                  • 6. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3

                    Thank you for the response.

                    JBM version: jboss-messaging-1.4.0.SP3

                    We have a pure app server which connects to JBM. we use durable subscribers. Only JBoss restart is solving the problem. client(my appserver) restart is not helping, which means creating new Connection and Session. Also when client is restarted we are able to see the following error: javax.jms.IllegalStateException: Cannot create a subscriber on the durable subscription since it already has subscriber(s)
                    . Here is the Jboss log


                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#0[127.0.0.1:3979] closing socketWrapper: ServerSocketWrapper[Socket[addr=/127.0.0.1,port=3979,localport=4457].117459c]
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.jms.server.remoting.ServerSocketWrapper] wrote CLOSING byte
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/127.0.0.1,port=3979,localport=4457].117459c] closing
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#1[127.0.0.1:3978] closing socketWrapper: ServerSocketWrapper[Socket[addr=/127.0.0.1,port=3978,localport=4457].db1df1]
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.jms.server.remoting.ServerSocketWrapper] wrote CLOSING byte
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/127.0.0.1,port=3978,localport=4457].db1df1] closing
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.InvokerRegistry] removed SocketClientInvoker[25724e, bisocket://10.11.151.170:2050639998] from registry
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[25724e, bisocket://10.11.151.170:2050639998] disconnecting ...2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ClientSocketWrapper[Socket[addr=/127.0.0.1,port=4235,localport=56656].1440636] closing
                    2009-07-14 17:57:51,925 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[ab474q-8irr1u-fx4e2z0n-1-fx4e2ze3-4+ab474q-8irr1u-fx4e2z0n-1-fx4e2zg9-9] shut down
                    2009-07-14 17:57:56,035 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Tue, 14 Jul 2009 17:57:56>
                    2009-07-14 17:57:56,035 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
                    2009-07-14 17:57:56,035 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
                    2009-07-14 17:57:56,035 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
                    2009-07-14 17:58:06,035 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Tue, 14 Jul 2009 17:58:06>
                    2009-07-14 17:58:06,035 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
                    2009-07-14 17:58:06,035 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
                    2009-07-14 17:58:06,035 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
                    2009-07-14 17:58:07,222 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 17:58:37,176 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 17:59:07,209 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 17:59:37,163 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:00:06,039 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Tue, 14 Jul 2009 18:00:06>
                    2009-07-14 18:00:06,039 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
                    2009-07-14 18:00:06,039 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
                    2009-07-14 18:00:06,039 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
                    2009-07-14 18:00:07,258 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:00:16,039 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Tue, 14 Jul 2009 18:00:16>
                    2009-07-14 18:00:16,039 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
                    2009-07-14 18:00:16,039 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
                    2009-07-14 18:00:16,039 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
                    2009-07-14 18:00:37,165 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:00:41,915 DEBUG [org.jboss.security.plugins.JaasSecurityManager.other] CallbackHandler: org.jboss.security.auth.callback.SecurityAssociationHandler@20183
                    2009-07-14 18:00:41,915 DEBUG [org.jboss.security.plugins.JaasSecurityManagerService] Created securityMgr=org.jboss.security.plugins.JaasSecurityManager@1b149b8
                    2009-07-14 18:00:41,915 DEBUG [org.jboss.security.plugins.JaasSecurityManager.other] CachePolicy set to: org.jboss.util.TimedCachePolicy@5ed714
                    2009-07-14 18:00:41,915 DEBUG [org.jboss.security.plugins.JaasSecurityManagerService] setCachePolicy, c=org.jboss.util.TimedCachePolicy@5ed714
                    2009-07-14 18:00:41,915 DEBUG [org.jboss.security.plugins.JaasSecurityManagerService] Added other, org.jboss.security.plugins.SecurityDomainContext@7a8310 to map
                    2009-07-14 18:01:07,072 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper] reset timeout: 60000
                    2009-07-14 18:01:07,103 DEBUG [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#5[127.0.0.1:2864] closing socketWrapper: ServerSocketWrapper[Socket[addr=/127.0.0.1,port=2864,localport=3873].d40369]
                    2009-07-14 18:01:07,103 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper] wrote CLOSING
                    2009-07-14 18:01:07,103 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/127.0.0.1,port=2864,localport=3873].d40369] closing
                    2009-07-14 18:01:07,213 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:01:11,541 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper] reset timeout: 60000
                    2009-07-14 18:01:11,541 DEBUG [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#5[127.0.0.1:2865] closing socketWrapper: ServerSocketWrapper[Socket[addr=/127.0.0.1,port=2865,localport=3873].55d58]
                    2009-07-14 18:01:11,541 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper] wrote CLOSING
                    2009-07-14 18:01:11,541 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/127.0.0.1,port=2865,localport=3873].55d58] closing
                    2009-07-14 18:01:13,853 DEBUG [org.jboss.remoting.transport.socket.ClientSocketWrapper] reset timeout: 60000
                    2009-07-14 18:01:13,869 DEBUG [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#5[127.0.0.1:2866] closing socketWrapper: ServerSocketWrapper[Socket[addr=/127.0.0.1,port=2866,localport=3873].bbd9e6]
                    2009-07-14 18:01:13,869 DEBUG [org.jboss.remoting.transport.socket.ServerSocketWrapper] wrote CLOSING
                    2009-07-14 18:01:13,869 DEBUG [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/127.0.0.1,port=2866,localport=3873].bbd9e6] closing
                    2009-07-14 18:01:37,167 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:02:07,214 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:02:16,043 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Tue, 14 Jul 2009 18:02:16>
                    2009-07-14 18:02:16,043 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
                    2009-07-14 18:02:16,043 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
                    2009-07-14 18:02:16,043 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
                    2009-07-14 18:02:26,043 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Tue, 14 Jul 2009 18:02:26>
                    2009-07-14 18:02:26,043 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
                    2009-07-14 18:02:26,043 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
                    2009-07-14 18:02:26,043 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
                    2009-07-14 18:02:37,184 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:03:07,216 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:03:37,170 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:04:07,234 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:04:26,047 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Tue, 14 Jul 2009 18:04:26>
                    2009-07-14 18:04:26,047 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
                    2009-07-14 18:04:26,047 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
                    2009-07-14 18:04:26,047 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
                    2009-07-14 18:04:36,047 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Tue, 14 Jul 2009 18:04:36>
                    2009-07-14 18:04:36,047 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
                    2009-07-14 18:04:36,047 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
                    2009-07-14 18:04:36,047 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
                    2009-07-14 18:04:37,188 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:05:07,220 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:05:37,190 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config
                    2009-07-14 18:06:07,269 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for SDSCMPCAMESSAGES1, using default security config

                    • 7. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3
                      gaohoward

                      Hi,

                      Please give the cp version of JBM, like 1.4.0.sp3-cp07.

                      The problem seems your client has crached before you close any subscribers/session/connections.

                      • 8. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3

                        Not sure how to get the CP version. in the Manifest file, i have this info

                        Manifest-Version: 1.0
                        Ant-Version: Apache Ant 1.7.0
                        Created-By: 1.5.0_13-b05 (Sun Microsystems Inc.)
                        Specification-Title: JBoss Messaging
                        Specification-Version: 1.4.0.SP3
                        Specification-Vendor: JBoss Inc. (http://www.jboss.org/)
                        Implementation-Title: JBoss Messaging
                        Implementation-URL: http://www.jboss.org/
                        Implementation-Version: 1.4.0.SP3 (build: CVSTag=JBossMessaging_1_4_0_
                        SP3 date=200712131418)
                        Implementation-Vendor: JBoss Inc. (http://www.jboss.org/)
                        Implementation-Vendor-Id: http://www.jboss.org/

                        • 9. Re: Messaging 1.4.0 SP3 with JBoss AS 4.2.3
                          gaohoward

                          OK you already have the version right. You are using the 1.4.0.sp3. Current release is 1.4.0.sp3-cp08 for EAP and 1.4.4.GA for JBoss 4.2.3.GA.
                          Can you try the latest version? They have a lot bug fixes.