14 Replies Latest reply on Dec 2, 2008 12:32 AM by Ron Sigal

    How to set ping timeout of ConnectionValidator?

    Hendra Sasmita Newbie

      Hi guys,

      Recently, I got a lot of connection problem when using jboss messaging. The clients (producer and consumer) throw connection exception which is captured by connection exception listener.

      This is happened repeatly at certain time every day.

      After further investigation, I find out that at that time, lots of cron jobs run on the server and make the ConnectionValidator failed to get the pong after it pings the server.

      In the client logs, I can see this:

      Code:

      [DEBUG] [DaemonRetry ] [MO] jboss.remoting.ConnectionValidator: ConnectionValidator[null, pi
      ngPeriod=2000 ms] created
      2008-09-23 16:59:36,288 [TRACE] [DaemonRetry ] [MO] jboss.remoting.ConnectionValidator: conf
      ig timeout: null
      2008-09-23 16:59:36,288 [DEBUG] [DaemonRetry ] [MO] jboss.remoting.ConnectionValidator: Conn
      ectionValidator[null, pingPeriod=2000 ms] timeout: 1000
      2008-09-23 16:59:36,289 [DEBUG] [DaemonRetry ] [MO] jboss.remoting.ConnectionValidator: Conn
      ectionValidator[null, pingPeriod=2000 ms] ping retries: 1
      2008-09-23 16:59:36,311 [DEBUG] [DaemonRetry ] [MO] jboss.remoting.ConnectionValidator: Conn
      ectionValidator[null, pingPeriod=2000 ms] connection retries: null



      The pingTimeout of ConnectionValidator is too short in my opinion (1 second)

      My question is: how to set the pingTimeout, pingPeriod, and max pingRetries of ConnectionValidator?

      Should it be set in remoting-bisocket-service.xml? Which variables need to be changed?

      I have read the jboss messaging, and remoting documentation, but I can't find exactly how I can set those values.

      Thank you in advance for your help.

      Best Regards,
      Hendra

      p.s.: I am using jboss 4.2.3.GA, jboss messaging 1.4.0.SP3.CP03, and jboss remoting 2.2.2.SP8

        • 1. Re: How to set ping timeout of ConnectionValidator?
          Ron Sigal Master

          Hi Hendra,

          "hendra_netm" wrote:

          My question is: how to set the pingTimeout, pingPeriod, and max pingRetries of ConnectionValidator?

          Should it be set in remoting-bisocket-service.xml? Which variables need to be changed?


          Use "validatorPingTimeout", "validatorPingPeriod", and "NumberOfCallRetries", respectively. That is, add something like

          <attribute name="validatorPingTimeout" isParam="true">5000</attribute>
          <attribute name="validatorPingPeriod" isParam="true">10000</attribute>
          <attribute name="NumberOfCallRetries" isParam="true">2</attribute>
          


          to remoting-bisocket-service.xml.

          -Ron

          • 2. Re: How to set ping timeout of ConnectionValidator?
            Mark Swanson Newbie

            I have put a nearly identical snippet of code in my remoting-bisocket-service.xml file, but these values remain unused. I can enable TRACE logging for the remoting and messaging packages, and see in the output that the original (default) connection timeout values of 1000 and period of 2000ms are used.

            Is there something else that needs to be done to make the client use these settings? I'm using JBRemoting 2.4.0 with JBM 1.4.0SP3.

            Mark

            • 3. Re: How to set ping timeout of ConnectionValidator?
              Mark Swanson Newbie

              Oh, one more tidbit. I did NOT change "NumberOfCallRetries" because a warning at JBoss startup indicated that I should not, and that I had to put a "disableRemotingChecks" entry in JBM somewhere, so I left that one item out. Do I need the "disableRemotingChecks" to enable my other changes as well, even though there was no warning for those?

              • 4. Re: How to set ping timeout of ConnectionValidator?
                Ron Sigal Master

                The attributes with isParam="true" should get added to the InvokerLocator, which is seen on the client side, where the ConnectionValidator should see them. When you start the Application Server, the InvokerLocator of each Remoting server is logged at DEBUG log level. E.g.:

                2008-11-11 02:51:25,890 DEBUG [org.jboss.remoting.ServerInvoker] (main) SocketServerInvoker[127.0.0.1:4457] started for locator InvokerLocator [bisocket://127.0.0.1:4457/?JBM_clientMaxPoolSize=200&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&stopLeaseOnFailure=true&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat]
                


                Could you see what your JBossMessaging InvokerLocator looks like? You can change the Remoting log level to DEBUG by adding

                 <category name="org.jboss.remoting">
                 <priority value="DEBUG"/>
                 </category>
                


                to server/$CONFIG/conf/jboss-log4j.xml

                • 5. Re: How to set ping timeout of ConnectionValidator?
                  Mark Swanson Newbie

                  Ron,

                  Yes it does appear these settings are propagated to the client as you indicated.

                  2008-11-19 01:15:47,389 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[Serenity.local:11457] started for locator InvokerLocator [bisocket://Serenity.local:11457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=20000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePingerTimeout=10000&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=2&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat&validatorPingPeriod=15000&validatorPingTimeout=10000]

                  I will attach a remoting / messaging package trace log on the client side when I get a chance. There is no debug nor trace msg that explicitly states the values when the connection validator is created, but when a timeout error occurs it's pretty clear. I looked through some of the source, but it's not immediately evident to me where the timeout would get set on the connection validator.

                  I'll attach more data when I can get it. Thanks for your nudge in the right direction. At least I now know the problem is on the client side.

                  Mark

                  • 6. Re: How to set ping timeout of ConnectionValidator?
                    Mark Swanson Newbie

                    Ron,

                    I can see this message on both sides of the connection:


                    2008-11-19 12:36:11,934 DEBUG [org.jboss.remoting.Client] starting callback Connector: InvokerLocator [bisocket://10.101.110.64:395136647/callback?callbackServerHost=10.101.110.64&callbackServerPort=395136647&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=a2t321s-96w9c6-fnqfpbmc-1-fnqfprfi-c1&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper]



                    12:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:114
                    57] setting maxPoolSize to 112:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:114
                    57] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper12:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:114
                    57] setting shouldCheckConnection to false12:36:56,881 DEBUG [SocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:11457] s
                    etting timeout to 012:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:114
                    57] constructed
                    12:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:114
                    57] setting maxPoolSize to 112:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:114
                    57] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
                    12:36:56,881 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:11457] setting shouldCheckConnection to false12:36:56,881 DEBUG [SocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:11457] s
                    etting timeout to 012:36:56,881 DEBUG [BisocketClientInvoker] Setting ping frequency to: 214748364
                    12:36:56,881 DEBUG [MicroRemoteClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:11457] connecting12:36:56,881 DEBUG [MicroSocketClientInvoker] Creating semaphore with size 112:36:56,881 TRACE [MicroSocketClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:11457] added new pool ([]) as ServerAddress[10.101.110.64:11457, NO enableTcpNoDelay timeout 0 ms, maxPoolSize=1]
                    12:36:56,881 DEBUG [MicroRemoteClientInvoker] SocketClientInvoker[207f7d58, bisocket://serenity.solarworldusa.net:11457] connected
                    12:36:56,882 DEBUG [Client] starting callback Connector: InvokerLocator [bisocket://10.101.110.64:1072374883/callback?callbackServerHost=10.101.110.64&callbackServerPort=1072374883&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=a2t321s-pldl5n-fnqfqp2i-1-fnqfqq41-g&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper]
                    12:36:56,953 DEBUG [ServerInvoker] SocketServerInvoker[10.101.110.64:1072374883] did not find server socket factory configuration as mbean service or classname. Creating default server socket factory.
                    12:36:56,954 DEBUG [ServerInvoker] SocketServerInvoker[10.101.110.64:1072374883] created server socket factory javax.net.DefaultServerSocketFactory@7c502d56
                    12:36:56,955 DEBUG [BisocketServerInvoker] SocketServerInvoker[10.101.110.64:1072374883] setting pingFrequency to 214748364
                    12:36:56,955 DEBUG [BisocketServerInvoker] SocketServerInvoker[10.101.110.64:1072374883] setting pingWindowFactor to 10
                    12:36:56,971 DEBUG [Connector] org.jboss.remoting.transport.Connector@61917b9e started
                    12:36:56,973 TRACE [LocalClientInvoker] Using local client invoker for invocation.
                    12:36:56,973 TRACE [ServerInvoker] SocketServerInvoker[10.101.110.64:1072374883] received InternalInvocation[3ea7f915]
                    12:36:56,973 TRACE [ServerInvoker] handling InternalInvocation where method name = addClientListener
                    12:36:56,974 DEBUG [ServerInvoker] ServerInvoker (SocketServerInvoker[10.101.110.64:1072374883]) added client callback handler CallbackManager[5514cd80] with session id of a2t321s-pldl5n-fnqfqp2i-1-fnqfqq12-c+a2t321s-pldl5n-fnqfqp2i-1-fnqfqq6k-h and callback handle object of null.
                    12:36:56,974 TRACE [ServerInvoker] SocketServerInvoker[10.101.110.64:1072374883] successfully dispatched invocation, returning null from subsystem 'JMS' to client a2t321s-pldl5n-fnqfqp2i-1-fnqfqq12-c
                    12:36:56,974 TRACE [InvokerRegistry] destroying client invoker InvokerLocator [bisocket://10.101.110.64:1072374883/callback?callbackServerHost=10.101.110.64&callbackServerPort=1072374883&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=a2t321s-pldl5n-fnqfqp2i-1-fnqfqq41-g&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper], config {}
                    12:36:56,974 DEBUG [InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@6ee3572b from registry
                    12:36:56,974 TRACE [InvokerRegistry] disconnecting org.jboss.remoting.transport.local.LocalClientInvoker@6ee3572b


                    Not sure if this helps, but I don't see anywhere in my client logs (TRACE level enabled for both org.jboss.remoting and org.jboss.messaging) that shows the validator timeout parameter being passed. It is clearly pinging every 2000ms (the default) even though I have the parameter configured differently.

                    The LeasePinger does in fact get my modified parameters (ping frequency = 20000ms):
                    <client log>
                    12:37:22,285 TRACE [LeasePinger] LeasePinger[SocketClientInvoker[e1ddc89, bisocket://serenity.solarworldusa.net:11457](a2t321s-ujh9t3-fnqfr96u-1-fnqfr9p4-e)] adding new client with session ID a2t321s-ujh9t3-fnqfr96u-1-fnqfr9p2-c and lease period 20000

                    I haven't verified the timeout, but I can probably set it to a very short period (10ms) and verify that the lease times out. Unsure why the lease pinger gets his parameters and the connection validator does not.

                    what else can i try?

                    Thanks,

                    Mark

                    • 7. Re: How to set ping timeout of ConnectionValidator?
                      Mark Swanson Newbie

                      OK, here's a juicy tid-bit I missed:

                      12:58:33,275 DEBUG [ConnectionValidator] ConnectionValidator[null, pingPeriod=2000 ms] created
                      12:58:33,275 TRACE [ConnectionValidator] config timeout: null
                      12:58:33,275 DEBUG [ConnectionValidator] ConnectionValidator[null, pingPeriod=2000 ms] timeout: 1000
                      12:58:33,275 DEBUG [ConnectionValidator] ConnectionValidator[null, pingPeriod=2000 ms] ping retries: 1
                      12:58:33,275 DEBUG [ConnectionValidator] ConnectionValidator[null, pingPeriod=2000 ms] connection retries: null

                      It's obvious that the connection validator is being created with default values. I just don't know where the server-side invoker parameters are being ignored.

                      • 8. Re: How to set ping timeout of ConnectionValidator?
                        Mark Swanson Newbie

                        Ron,

                        Among all the debug entries I posted, I realized I was missing the one line you asked for. Client side again:

                        13:11:58,759 DEBUG [Client] starting callback Connector: InvokerLocator [bisocket://10.101.110.64:1878752913/callback
                        ?callbackServerHost=10.101.110.64&callbackServerPort=1878752913&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=a2t321s-u0b7nn-fnqgzrc3-1-fnqgzr
                        xj-g&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper]

                        It does appear that most of the server-side parameters are not passed.

                        Mark

                        • 9. Re: How to set ping timeout of ConnectionValidator?
                          Mark Swanson Newbie

                          server-side locator entry:

                          2008-11-19 13:05:30,933 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[serenity.solarworldusa.net:11457] started for locator InvokerLocator [bisoc
                          ket://serenity.solarworldusa.net:11457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=20000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&da
                          taType=jms&leasePingerTimeout=1&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=2&pingFrequency=214748364&pingWindowFactor=10&socket.check
                          _connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat&validatorPingPeriod=5000&validatorPingTimeout=1]

                          • 10. Re: How to set ping timeout of ConnectionValidator?
                            Ron Sigal Master

                            Hi Mark,

                            The InvokerLocator you see on the server side is the one that matters, and it has the desired parameters. The one you see on the client side,

                            13:11:58,759 DEBUG [Client] starting callback Connector: InvokerLocator [bisocket://10.101.110.64:1878752913/callback
                            ?callbackServerHost=10.101.110.64&callbackServerPort=1878752913&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=a2t321s-u0b7nn-fnqgzrc3-1-fnqgzr
                            xj-g&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting]
                            


                            is for the callback Connector to which the server pushes messages, which isn't related to the ConnectionValidator, and you can ignore it.

                            What should happen in JBossMessaging is that it sends the InvokerLocator from the server to the client, where it is used to create the necessary instances of org.jboss.remoting.Client. See, for example, the JBM class org.jboss.jms.client.remoting.JMSRemotingConnection. When the Client creates a ConnectionValidator, the ConnectionValidator uses the Client's parameters, including those from the InvokerLocator, to configure itself. See org.jboss.remoting.ConnectionValidator.start(). I don't know why your parameters aren't making it into the ConnectionValidator. One thing to try, if you don't see anything interesting in the logs, is to attach a debugger to your client. Even if Bill Burke says "debuggers are for pussies". :)

                            -Ron

                            • 11. Re: How to set ping timeout of ConnectionValidator?
                              Mark Swanson Newbie

                              Ron,

                              Attempting to follow the remoting / messaging code that is quite new to me, I think I follow what you have said. However, attempting to backtrack through the call chain to see where the URI is passed from server to client I quickly get lost.

                              I think I have discovered the appropriate InvokerLocator URI that is for the Client object (below?) in the debug log:

                              05:30:03,958 DEBUG [InvokerLocator] creating InvokerLocator with URI: bisocket://mobile-166-129-196-099.mycingular.net:11457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=10000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat


                              which includes most parameters, but not my custom validation entries. I haven't tried to set up all the remoting & messaging source such that I can step through this with a debugger. I have compiled both remoting and messaging source and inserted some additional debug statements to attempt to trace the URI. However, it is extremely cumbersome (it has taken me days to get this far!).

                              Any quick hints which classes I can look at on the server side (where the URI is constructed and passed to the client) and on the client side (where it's received before JMSRemotingConnection is created with it)? There are so many layers of indirection and cross-connections for the bisocket that I feel completely lost :)

                              Thanks,

                              Mark

                              • 12. Re: How to set ping timeout of ConnectionValidator?
                                Ron Sigal Master

                                Hi Mark,

                                Yes, the JBossMessaging code is quite elegant, but there's a steep learning curve. I've been there. :)

                                Unfortunately, it's been at least a year and a half since I've last had a good understanding of their code, so I don't have a quick answer for you. However, when I get a chance, I will see if I can see what's going on. I'd like to know if there's a Remoting problem involved.

                                By the way, I just discovered a related problem, though it affects only the ping period, not the ping timeout. It's described in JBREM-1069 "Make ConnectorValidator configure ping period correctly".

                                -Ron

                                • 13. Re: How to set ping timeout of ConnectionValidator?
                                  Mark Swanson Newbie

                                  Ron,

                                  Looks like someone else ran across the exact same bug (but thinks it will fix the situation for all client parameters, not just the ping timeout. This was posted to the JBM forums today.

                                  http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4193633#4193633

                                  I may make this code change and test myself if I have time. I'm not 100% sure my parameters are making it across the socket connection to the client invoker locator, but I am curious to try this if I have time.

                                  Mark

                                  • 14. Re: How to set ping timeout of ConnectionValidator?
                                    Ron Sigal Master

                                    Thanks, Mark. I responded in the other forum.

                                    I don't think that problem, described in https://jira.jboss.org/jira/browse/JBREM-1069, woud affect any parameter except "validatorPingPeriod", but maybe I'm missing something.

                                    -Ron