1 2 Previous Next 15 Replies Latest reply on Jan 21, 2013 2:59 AM by kieselhorst

    Remote method call fails after 30 minutes

    Thorben Janssen Newbie

      Hi,

       

      we are working with JBoss AS 7.1.1 and run into the following problem during remote calls:

      Our client creates an InitialContext during startup and caches it. Everything works fine as long as the user keeps using the client application. But if the client is not used for at least 30 minutes, the connection seems to be broken and the next remote method call will not return. I see the bean reference in the debugger, so the lookup seems to work. Some time after the client tried to call the method on the SLSB, JBoss writes this message to the log:

      01:59:34,863 ERROR [org.jboss.remoting.remote.connection] (Remoting "testserver" read-1) JBREM000200: Remote connection failed: java.io.IOException: Eine vorhandene Verbindung wurde vom Remotehost geschlossen

       

      Everything works fine, if I create a new InitialContext for each server request.

       

      Any ideas how to solve this issue?

      Is it wrong to keep a reference on the InitialContext? In the past it was done because it took some time to create the InitialContext, but it seems to be ok now.

       

      edit:

      We use this code to setup the connection and to create the InitialContext:

      // define the JBoss client properties
              final Properties clientProperties = new Properties();
              clientProperties.put("remote.connectionprovider.create.options.org.xnio.Options.SSL_ENABLED", "false");
              clientProperties.put("remote.connections", "default");
      
              clientProperties.put("remote.connection.default.host", this.hostName);
              clientProperties.put("remote.connection.default.port", Integer.toString(this.portNumber));
      
              clientProperties.put("remote.connection.default.username", userName);
              if (password != null) {
                  clientProperties.put("remote.connection.default.password", password);
              }
      
              clientProperties.put("remote.connection.default.connect.options.org.xnio.Options.SASL_DISALLOWED_MECHANISMS",
                      "JBOSS-LOCAL-USER");
              clientProperties.put("remote.connection.default.connect.options.org.xnio.Options.SASL_POLICY_NOPLAINTEXT",
                      "false");
      
              // create client configuration
              final EJBClientConfiguration clientConfiguration = new PropertiesBasedEJBClientConfiguration(clientProperties);
      
              // create a context selector
              final ContextSelector<EJBClientContext> contextSelector = new ConfigBasedEJBClientContextSelector(
                      clientConfiguration);
      
              // set the selector for use
              EJBClientContext.setSelector(contextSelector);
      
              try {
                  final Hashtable<Object, Object> contextProperties = new Hashtable<>();
                  ejbURLContextFactory.class.getName();
                  contextProperties.put(Context.URL_PKG_PREFIXES, "org.jboss.ejb.client.naming");
                  this.initialContext = new InitialContext(contextProperties);
              } catch (final NamingException ex) {
                  throw new RuntimeException(ex);
              }
      

       

       

      Thanks a lot!

      Thorben

       

      Add code for connection setup and InitialContext creation

        • 1. Re: Remote method call fails after 30 minutes
          Wolf-Dieter Fink Master

          Hi Thorben,

           

          do you see any messages in the log if you set 'org.jboss.ejb' to TRACE at the client and ... mmmh org.jboss.remote (remoting) and org.xnio to TRACE at server side?

          I suppose you leave the test without load for 30mins, right?

          • 2. Re: Remote method call fails after 30 minutes
            Thorben Janssen Newbie

            Wolf-Dieter Fink schrieb:


            I suppose you leave the test without load for 30mins, right?

             

            Yes, there is no load on the client and therefore there are no requests send to JBoss. There are no additional clients in my test environment, so there is also no server load during the 30mins.

             

            Wolf-Dieter Fink schrieb:

             

            do you see any messages in the log if you set 'org.jboss.ejb' to TRACE at the client

            Sorry, I cannot provide a client log at the moment

             

             

            Wolf-Dieter Fink schrieb:

            do you see any messages in the log if you set [...] org.jboss.remote (remoting) and org.xnio to TRACE at server side?

            This is writte to the server log:

            07:47:33,835 TRACE [org.xnio.channels.framed] (Remoting "testserver" read-1) Did not read a length
            07:47:33,836 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Beginning select on sun.nio.ch.WindowsSelectorImpl@5a424a96
            08:52:01,337 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Selected on sun.nio.ch.WindowsSelectorImpl@5a424a96
            08:52:01,338 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Selected key sun.nio.ch.SelectionKeyImpl@1ba62063 for java.nio.channels.SocketChannel[connected local=testserver/192.168.11.62:4447 remote=/192.168.10.146:51059]
            08:52:01,338 TRACE [org.xnio.listener] (Remoting "testserver" read-1) Invoking listener Read listener for org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956> on channel TCP socket channel (NIO) <2599e956>
            08:52:01,339 TRACE [org.xnio.listener] (Remoting "testserver" read-1) Invoking listener org.jboss.remoting3.remote.RemoteReadListener@4abf8d4e on channel org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:01,339 TRACE [org.xnio.channels.framed] (Remoting "testserver" read-1) Copying message from java.nio.HeapByteBuffer[pos=4 lim=158 cap=8196] into java.nio.HeapByteBuffer[pos=0 lim=8192 cap=8192]
            08:52:01,341 TRACE [org.xnio.channels.framed] (Remoting "testserver" read-1) Did not read a length
            08:52:01,343 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Beginning select on sun.nio.ch.WindowsSelectorImpl@5a424a96
            08:52:01,343 TRACE [org.xnio.channels.framed] (Remoting "testserver" task-2) Accepting java.nio.HeapByteBuffer[pos=0 lim=11 cap=8192] into java.nio.HeapByteBuffer[pos=0 lim=8196 cap=8196]
            08:52:01,343 TRACE [org.xnio.channels.framed] (Remoting "testserver" task-2) Accepted a message into java.nio.HeapByteBuffer[pos=15 lim=8196 cap=8196]
            08:52:01,344 TRACE [org.xnio.channels.framed] (Remoting "testserver" task-2) Fully flushed org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:01,359 TRACE [org.xnio.safe-close] (Remoting "testserver" task-2) Closing resource org.jboss.remoting3.remote.InboundMessage$3@6dfb9261
            08:52:01,402 INFO  [stdout] (EJB default - 4) Hibernate: select [...]
            
            08:52:01,420 TRACE [org.xnio.channels.framed] (EJB default - 4) Accepting java.nio.HeapByteBuffer[pos=0 lim=1639 cap=8192] into java.nio.HeapByteBuffer[pos=0 lim=8196 cap=8196]
            08:52:01,420 TRACE [org.xnio.channels.framed] (EJB default - 4) Accepted a message into java.nio.HeapByteBuffer[pos=1643 lim=8196 cap=8196]
            08:52:01,421 TRACE [org.xnio.channels.framed] (EJB default - 4) Fully flushed org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:01,421 TRACE [org.xnio.channels.framed] (EJB default - 4) Fully flushed org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:01,421 TRACE [org.xnio.channels.framed] (EJB default - 4) Accepting java.nio.HeapByteBuffer[pos=0 lim=8 cap=8192] into java.nio.HeapByteBuffer[pos=0 lim=8196 cap=8196]
            08:52:01,422 TRACE [org.xnio.channels.framed] (EJB default - 4) Accepted a message into java.nio.HeapByteBuffer[pos=12 lim=8196 cap=8196]
            08:52:01,422 TRACE [org.xnio.channels.framed] (EJB default - 4) Fully flushed org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:01,422 TRACE [org.xnio.channels.framed] (EJB default - 4) Fully flushed org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:22,852 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Selected on sun.nio.ch.WindowsSelectorImpl@5a424a96
            08:52:22,852 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Selected key sun.nio.ch.SelectionKeyImpl@1ba62063 for java.nio.channels.SocketChannel[connected local=testserver/192.168.11.62:4447 remote=/192.168.10.146:51059]
            08:52:22,852 TRACE [org.xnio.listener] (Remoting "testserver" read-1) Invoking listener Read listener for org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956> on channel TCP socket channel (NIO) <2599e956>
            08:52:22,853 TRACE [org.xnio.listener] (Remoting "testserver" read-1) Invoking listener org.jboss.remoting3.remote.RemoteReadListener@4abf8d4e on channel org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:22,854 ERROR [org.jboss.remoting.remote.connection] (Remoting "testserver" read-1) JBREM000200: Remote connection failed: java.io.IOException: Eine vorhandene Verbindung wurde vom Remotehost geschlossen
            08:52:22,854 TRACE [org.xnio.safe-close] (Remoting "testserver" read-1) Closing resource org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:22,854 TRACE [org.xnio.channels.framed] (Remoting "testserver" read-1) Fully flushed org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:22,855 TRACE [org.xnio.nio.tcp.channel] (Remoting "testserver" read-1) Closing TCP socket channel (NIO) <2599e956>
            08:52:22,855 TRACE [org.xnio.nio] (Remoting "testserver" read-1) Cancelling key sun.nio.ch.SelectionKeyImpl@1ba62063 of java.nio.channels.SocketChannel[closed] (same thread)
            08:52:22,855 TRACE [org.xnio.nio.selector] (Remoting "testserver" write-1) Selected on sun.nio.ch.WindowsSelectorImpl@235b7c7f
            08:52:22,855 TRACE [org.xnio.nio] (Remoting "testserver" read-1) Cancelling key sun.nio.ch.SelectionKeyImpl@379851c3 of java.nio.channels.SocketChannel[closed] (other thread)
            08:52:22,856 TRACE [org.xnio.nio.selector] (Remoting "testserver" write-1) Beginning select on sun.nio.ch.WindowsSelectorImpl@235b7c7f (with timeout)
            08:52:22,856 TRACE [org.xnio.listener] (Remoting "testserver" read-1) Invoking listener Close listener for org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956> on channel TCP socket channel (NIO) <2599e956>
            08:52:22,856 TRACE [org.xnio.nio.selector] (Remoting "testserver" write-1) Selected on sun.nio.ch.WindowsSelectorImpl@235b7c7f
            08:52:22,856 TRACE [org.xnio.safe-close] (Remoting "testserver" read-1) Closing resource org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:22,857 TRACE [org.xnio.nio.selector] (Remoting "testserver" write-1) Beginning select on sun.nio.ch.WindowsSelectorImpl@235b7c7f (with timeout)
            08:52:22,857 TRACE [org.xnio.safe-close] (Remoting "testserver" read-1) Closing resource TCP socket channel (NIO) <2599e956>
            08:52:22,857 TRACE [org.xnio.listener] (Remoting "testserver" read-1) Invoking listener org.jboss.remoting3.remote.RemoteReadListener$1@4f2dd7fe on channel org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            08:52:22,858 TRACE [org.xnio.nio.selector] (Remoting "testserver" read-1) Beginning select on sun.nio.ch.WindowsSelectorImpl@5a424a96
            08:52:22,858 TRACE [org.xnio.safe-close] (Remoting "testserver" task-3) Closing resource org.xnio.channels.FramedMessageChannel around TCP socket channel (NIO) <2599e956>
            
            • 3. Re: Remote method call fails after 30 minutes
              jaikiran pai Master

              Try adding this to the EJB3 subsystem in standalone*.xml:

               

              <subsystem xmlns="urn:jboss:domain:ejb3 ....>
              ...
                  <remote connector-ref="remoting-connector" thread-pool-name="default">
                      <channel-creation-options>
                          <option name="KEEP_ALIVE" value="true" type="xnio"/>
                      </channel-creation-options>
                  </remote>

              • 4. Re: Remote method call fails after 30 minutes
                Thorben Janssen Newbie
                Message: JBAS014789: Unexpected element '{urn:jboss:domain:ejb3:1.2}channel-creation-options' encountered
                

                 

                Do I need to update to AS 7.1.2? Currently using 7.1.1.

                • 5. Re: Remote method call fails after 30 minutes
                  jaikiran pai Master

                  Yes, I had forgotten that we introduced this post 7.1.1.

                  • 6. Re: Remote method call fails after 30 minutes
                    Thorben Janssen Newbie

                    I build 7.1.2 and it seems that I run into https://issues.jboss.org/browse/AS7-4824 now.

                    Is there a tag for 7.1.3? If not, is the release already scheduled?

                    • 8. Re: Remote method call fails after 30 minutes
                      Wolf-Dieter Fink Master

                      Hi Thorben,

                       

                      no there is no release 7.1.3.

                      If you use a git clone you might use the tag '7.1.3.Beta1' or switch to branch '7.1-next' which is the preparation for 7.1.3 final.

                       

                      Wolf

                       

                      Ooops looks like I missed a tag

                       

                      Message was edited by: Wolf-Dieter Fink

                      • 9. Re: Remote method call fails after 30 minutes
                        Wolf-Dieter Fink Master

                        "git fetch --tag upstream master"

                        solve it if you follow the Hacking guide when cloning AS7

                        • 10. Re: Remote method call fails after 30 minutes
                          Thorben Janssen Newbie

                          Hi Wolf and Jaikiran,

                           

                          thanks a lot for your support and sorry for my late reply.

                           

                          I setup an AS 7.1.3 with KEEP_ALIVE option but it still does not work

                          Its the same as before. The request does not return to the client, but I see in the server log that the request is processed by the AS. A few seconds later, I see the JBREM000200 error code in the AS log file.

                           

                          Any ideas?

                           

                          Thorben

                           

                           

                           

                          edit:

                          It seems to work with AS 7.1.1 if I set the property remote.connection.default.connect.options.org.jboss.remoting3.RemotingOptions.HEARTBEAT_INTERVAL on the connection properties passed to PropertiesBasedEJBClientConfiguration.

                          Are there any drawbacks with this workaround?

                          • 11. Re: Remote method call fails after 30 minutes
                            jaikiran pai Master

                            Thorben Janssen wrote:

                             

                             

                            edit:

                            It seems to work with AS 7.1.1 if I set the property remote.connection.default.connect.options.org.jboss.remoting3.RemotingOptions.HEARTBEAT_INTERVAL on the connection properties passed to PropertiesBasedEJBClientConfiguration.

                            Are there any drawbacks with this workaround?

                            I just had a discussion about this with David and setting the HEARTBEAT_INTERVAL is the right way to do it.

                            1 of 1 people found this helpful
                            • 12. Re: Remote method call fails after 30 minutes
                              Thorben Janssen Newbie

                              Thanks Jaikiran!

                              Any suggestions to which value the interval should be set? Currently it's 10 min.

                              • 13. Re: Remote method call fails after 30 minutes
                                kieselhorst Newbie

                                Thanks for this helpful thread. IMHO the value depends on your firewall configuration, we are currently trying 5 mins.

                                 

                                For anybody else reading this: The interval has to be specified in milliseconds.

                                • 14. Configuring HEARTBEAT_INTERVAL for server to server communication
                                  Sudhakar Pyndi Newbie

                                  Hi Dennis,

                                   

                                  How does this Heartbeat property work from one Jboss server to another Jboss server context? In our case, we have the application UI deployed in one Jboss container and it looks up the EJBs in another JBoss container. We see the "JBREM000200: Remote connection failed: java.io.IOException:" exception in the JBoss application server where the UI is deployed when the EJBs in the other JBoss server are accessed the very first time after a long interval.

                                   

                                  Also, when I'm trying to set the HEARTBEAT_INTERVAL property in JBoss 7.1.2, it is throwing the following exception during JBoss server startup (it looks like the property tag is not defined):

                                  Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[512,17]

                                  Message: JBAS014789: Unexpected element '{urn:jboss:domain:remoting:1.1}properties' encountered

                                          at org.jboss.as.controller.parsing.ParseUtils.unexpectedElement(ParseUtils.java:85) [jboss-as-controller-7.1.2.Final.jar:7.1.2.Final]

                                          at org.jboss.as.remoting.RemotingSubsystem11Parser.parseOutboundConnections(RemotingSubsystem11Parser.java:420) [jboss-as-remoting-7.1.2.Final.jar:7.1.2.Final]

                                          at org.jboss.as.remoting.RemotingSubsystem11Parser.readElement(RemotingSubsystem11Parser.java:130) [jboss-as-remoting-7.1.2.Final.jar:7.1.2.Final]

                                   

                                  This is the setup/property I have in my standalone.xml file:

                                      <subsystem xmlns="urn:jboss:domain:remoting:1.1">

                                              <connector name="remoting-connector" socket-binding="remoting"/>

                                              <outbound-connections>

                                                  <remote-outbound-connection name="default" outbound-socket-binding-ref="default"/>

                                                  <remote-outbound-connection name="com.test.api" outbound-socket-binding-ref="test"/>

                                                  <properties>

                                                     <property name="SSL_ENABLED" value="false"/>

                                                     <property name="SASL_POLICY_NOANONYMOUS" value="false"/>

                                                     <property name="KEEP_ALIVE" value="true"/>

                                                     <property name="org.jboss.remoting3.RemotingOptions.HEARTBEAT_INTERVAL" value="1000"/>

                                                  </properties>

                                              </outbound-connections>

                                          </subsystem>

                                   

                                  Does the Heartbeat property work for you in JBoss 7.1.2? Could you please let me know the property definition? (ie, what file? how you have added the property?)

                                  Do we have to add the Heartbeat property in the jboss-ejb-client.xml file?

                                   

                                  Thank you in advance.

                                   

                                  Sudhakar

                                  1 2 Previous Next