Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-25258

[GSS](8.0.z) UNDERTOW-2228 - Undertow write-timeout can cause a closing TCP connection without response for long-running remote EJB request

XMLWordPrintable

    • False
    • None
    • False
    • Hide

      Set heartbeat-interval to a value shorter than the undertow write-timeout in src/main/resources/wildfly-config.xml on the EJB client side. If the write-timeout is set to 10000 ms in http-listener, apply heartbeat-interval="5000" as below.

      <?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <jboss-ejb-client xmlns="urn:jboss:wildfly-client-ejb:3.0">
        <connections>
            <connection uri="remote+http://127.0.0.1:8080"/>
        </connections>
    </jboss-ejb-client>
    <endpoint xmlns="urn:jboss-remoting:5.1" heartbeat-interval="5000">
        <connections/>
    </endpoint>
</configuration>
      Show
      Set heartbeat-interval to a value shorter than the undertow write-timeout in src/main/resources/wildfly-config.xml on the EJB client side. If the write-timeout is set to 10000 ms in http-listener, apply heartbeat-interval="5000" as below. <?xml version= "1.0" encoding= "UTF-8" ?> <configuration> <jboss-ejb-client xmlns= "urn:jboss:wildfly-client-ejb:3.0" > <connections> <connection uri= "remote+http: //127.0.0.1:8080" /> </connections> </jboss-ejb-client> <endpoint xmlns= "urn:jboss-remoting:5.1" heartbeat-interval= "5000" > <connections/> </endpoint> </configuration>
    • Hide

      Simple reproduction app reproducer-app.zip is attached on this issue report.

      1. build and deploy ejb-server app

      cd reproducer-app/ejb-server
mvn package
cp target/ejb-server.jar JBOSS_EAP_7.4.10_HOME/standalone/deployments/

      2. Set undertow write-timeout to 10000 ms in http-listener:

      JBOSS_HOME/bin/jboss-cli.sh -c
[standalone@localhost:9990 /] /subsystem=undertow/server=default-server/http-listener=default:write-attribute(name=write-timeout,value=10000)
[standalone@localhost:9990 /] reload

      3. Open a new console, then run the standalone EJB client app.

      cd reproducer-app/standalone-ejb-client-eap7
mvn compile exec:java -Dexec.mainClass=com.redhat.gss.client.Client
...
[WARNING] 
javax.ejb.EJBException: java.nio.channels.ClosedChannelException
    at org.jboss.ejb.protocol.remote.EJBClientChannel$MethodInvocation.handleClosed (EJBClientChannel.java:1287)
    at org.jboss.remoting3.util.InvocationTracker.connectionClosed (InvocationTracker.java:222)
    at org.jboss.remoting3.util.InvocationTracker.lambda$new$0 (InvocationTracker.java:70)
    at org.jboss.remoting3.spi.SpiUtils.safeHandleClose (SpiUtils.java:50)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable$CloseHandlerTask.run (AbstractHandleableCloseable.java:520)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable.runCloseTask (AbstractHandleableCloseable.java:425)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeComplete (AbstractHandleableCloseable.java:286)
    at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction (RemoteConnectionChannel.java:510)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync (AbstractHandleableCloseable.java:368)
    at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels (RemoteConnectionHandler.java:623)
    at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest (RemoteConnectionHandler.java:226)
    at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:97)
    at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:51)
    at org.xnio.ChannelListeners.invokeChannelListener (ChannelListeners.java:92)
    at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady (ReadReadyHandler.java:66)
    at org.xnio.nio.NioSocketConduit.handleReady (NioSocketConduit.java:89)
    at org.xnio.nio.WorkerThread.run (WorkerThread.java:591)
Caused by: java.nio.channels.ClosedChannelException
    at org.jboss.ejb.protocol.remote.EJBClientChannel$MethodInvocation.handleClosed (EJBClientChannel.java:1287)
    at org.jboss.remoting3.util.InvocationTracker.connectionClosed (InvocationTracker.java:222)
    at org.jboss.remoting3.util.InvocationTracker.lambda$new$0 (InvocationTracker.java:70)
    at org.jboss.remoting3.spi.SpiUtils.safeHandleClose (SpiUtils.java:50)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable$CloseHandlerTask.run (AbstractHandleableCloseable.java:520)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable.runCloseTask (AbstractHandleableCloseable.java:425)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeComplete (AbstractHandleableCloseable.java:286)
    at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction (RemoteConnectionChannel.java:510)
    at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync (AbstractHandleableCloseable.java:368)
    at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels (RemoteConnectionHandler.java:623)
    at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest (RemoteConnectionHandler.java:226)
    at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:97)
    at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:51)
    at org.xnio.ChannelListeners.invokeChannelListener (ChannelListeners.java:92)
    at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady (ReadReadyHandler.java:66)
    at org.xnio.nio.NioSocketConduit.handleReady (NioSocketConduit.java:89)
    at org.xnio.nio.WorkerThread.run (WorkerThread.java:591)
      Show
      Simple reproduction app reproducer-app.zip is attached on this issue report. 1. build and deploy ejb-server app cd reproducer-app/ejb-server mvn package cp target/ejb-server.jar JBOSS_EAP_7.4.10_HOME/standalone/deployments/ 2. Set undertow write-timeout to 10000 ms in http-listener: JBOSS_HOME/bin/jboss-cli.sh -c [standalone@localhost:9990 /] /subsystem=undertow/server= default -server/http-listener= default :write-attribute(name=write-timeout,value=10000) [standalone@localhost:9990 /] reload 3. Open a new console, then run the standalone EJB client app. cd reproducer-app/standalone-ejb-client-eap7 mvn compile exec:java -Dexec.mainClass=com.redhat.gss.client.Client ... [WARNING] javax.ejb.EJBException: java.nio.channels.ClosedChannelException at org.jboss.ejb.protocol.remote.EJBClientChannel$MethodInvocation.handleClosed (EJBClientChannel.java:1287) at org.jboss.remoting3.util.InvocationTracker.connectionClosed (InvocationTracker.java:222) at org.jboss.remoting3.util.InvocationTracker.lambda$ new $0 (InvocationTracker.java:70) at org.jboss.remoting3.spi.SpiUtils.safeHandleClose (SpiUtils.java:50) at org.jboss.remoting3.spi.AbstractHandleableCloseable$CloseHandlerTask.run (AbstractHandleableCloseable.java:520) at org.jboss.remoting3.spi.AbstractHandleableCloseable.runCloseTask (AbstractHandleableCloseable.java:425) at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeComplete (AbstractHandleableCloseable.java:286) at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction (RemoteConnectionChannel.java:510) at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync (AbstractHandleableCloseable.java:368) at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels (RemoteConnectionHandler.java:623) at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest (RemoteConnectionHandler.java:226) at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:97) at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:51) at org.xnio.ChannelListeners.invokeChannelListener (ChannelListeners.java:92) at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady (ReadReadyHandler.java:66) at org.xnio.nio.NioSocketConduit.handleReady (NioSocketConduit.java:89) at org.xnio.nio.WorkerThread.run (WorkerThread.java:591) Caused by: java.nio.channels.ClosedChannelException at org.jboss.ejb.protocol.remote.EJBClientChannel$MethodInvocation.handleClosed (EJBClientChannel.java:1287) at org.jboss.remoting3.util.InvocationTracker.connectionClosed (InvocationTracker.java:222) at org.jboss.remoting3.util.InvocationTracker.lambda$ new $0 (InvocationTracker.java:70) at org.jboss.remoting3.spi.SpiUtils.safeHandleClose (SpiUtils.java:50) at org.jboss.remoting3.spi.AbstractHandleableCloseable$CloseHandlerTask.run (AbstractHandleableCloseable.java:520) at org.jboss.remoting3.spi.AbstractHandleableCloseable.runCloseTask (AbstractHandleableCloseable.java:425) at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeComplete (AbstractHandleableCloseable.java:286) at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction (RemoteConnectionChannel.java:510) at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync (AbstractHandleableCloseable.java:368) at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels (RemoteConnectionHandler.java:623) at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest (RemoteConnectionHandler.java:226) at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:97) at org.jboss.remoting3.remote.RemoteReadListener.handleEvent (RemoteReadListener.java:51) at org.xnio.ChannelListeners.invokeChannelListener (ChannelListeners.java:92) at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady (ReadReadyHandler.java:66) at org.xnio.nio.NioSocketConduit.handleReady (NioSocketConduit.java:89) at org.xnio.nio.WorkerThread.run (WorkerThread.java:591)

      The TCP connection is closed from remote EJB server side before an EJB client receives a response under the following conditions:

      • The remote EJB request processing takes longer than jboss-remoting HEARTBEAT interval (default: 60000 ms)
      • Undertow write-timeout is set shorter than jboss-remoting HEARTBEAT.

      When this issue happens, the standalone EJB client will show the following stack trace in the console:

      Exception in thread "main" javax.ejb.EJBException: java.nio.channels.ClosedChannelException
	at org.jboss.ejb.protocol.remote.EJBClientChannel$MethodInvocation.handleClosed(EJBClientChannel.java:1287)
	at org.jboss.remoting3.util.InvocationTracker.connectionClosed(InvocationTracker.java:222)
	at org.jboss.remoting3.util.InvocationTracker.lambda$new$0(InvocationTracker.java:70)
	at org.jboss.remoting3.spi.SpiUtils.safeHandleClose(SpiUtils.java:50)
	at org.jboss.remoting3.spi.AbstractHandleableCloseable$CloseHandlerTask.run(AbstractHandleableCloseable.java:520)
	at org.jboss.remoting3.spi.AbstractHandleableCloseable.runCloseTask(AbstractHandleableCloseable.java:425)
	at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeComplete(AbstractHandleableCloseable.java:286)
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction(RemoteConnectionChannel.java:510)
	at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:368)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels(RemoteConnectionHandler.java:623)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest(RemoteConnectionHandler.java:226)
	at org.jboss.remoting3.remote.RemoteReadListener.handleEvent(RemoteReadListener.java:97)
	at org.jboss.remoting3.remote.RemoteReadListener.handleEvent(RemoteReadListener.java:51)
	at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
	at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66)
	at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89)
	at org.xnio.nio.WorkerThread.run(WorkerThread.java:591)
Caused by: java.nio.channels.ClosedChannelException
	... 17 more

      I suspect the root cause is the same as JBEAP-24358. However, this issue is reproduced with jboss-remoting, not a servlet request. I filed this issue so that QE scenarios with jboss-remoting will also be covered when JBEAP-24358 is fixed.

      Unlike HTTP and AJP, a remote EJB server returns a MESSAGE_CLOSE message in the remoting protocol when an entire remote request message is received from client-side. The write-timeout timer starts when the Remote EJB request is received.

      After 60 seconds have elapsed from the request being received, a remoting HEARTBEAT message is sent by the EJB client side. Then, the EJB server sends a CONNECTION_ALIVE_ACK as an ack to HEARTBEAT, but closes the TCP connection immediately afterward. When the EJB server writes the ack to HEARTBEAT, undertow write-timeout has already been exceeded, so the TCP connection is closed from the server side without waiting for the remote EJB processing to complete. As a result, no remote EJB response is returned to the client.

              thofman Tomas Hofman
              pberan@redhat.com Petr Beran
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated:
                Resolved: