Uploaded image for project: 'XNIO'
  1. XNIO
  2. XNIO-427

ClosedChannelException when NioSocketConduit.handleReady invokes write listener after read listener closes connection

XMLWordPrintable

      When NioSocketConduit.handleReady invokes both the read listener and the write listener (when selector has both operations enabled) and read listener reads a -1, the connection will be closed by the read listener before the write listener is invoked. In that case, when write listener is invoked, if it has data to write to the connection, a ClosedChannelConnection will result.
      See the stack trace below:

      2023-12-15 16:46:20,383 TRACE [org.xnio.nio.selector] (default I/O-6) Selected key channel=java.nio.channels.SocketChannel[connected local=ci-vm-10-0-151-92.hosted.upshift.rdu2.redhat.com/10.0.151.92:8080 remote=/10.0.151.93:43056], selec
tor=sun.nio.ch.EPollSelectorImpl@41422a92, interestOps=5, readyOps=5 for java.nio.channels.SocketChannel[connected local=ci-vm-10-0-151-92.hosted.upshift.rdu2.redhat.com/10.0.151.92:8080 remote=/10.0.151.93:43056]
2023-12-15 16:46:20,384 TRACE [org.xnio.nio.selector] (default I/O-6) Calling handleReady key 5 for java.nio.channels.SocketChannel[connected local=ci-vm-10-0-151-92.hosted.upshift.rdu2.redhat.com/10.0.151.92:8080 remote=/10.0.151.93:4305
6]
2023-12-15 16:46:20,384 TRACE [org.xnio.listener] (default I/O-6) Invoking listener org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial@40e65dc4 on channel org.xnio.conduits.ConduitStreamSourceChannel@634400b0
2023-12-15 16:46:20,384 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) No buffers in queue for message header
2023-12-15 16:46:20,385 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Allocated fresh buffers
2023-12-15 16:46:20,390 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Received EOF
2023-12-15 16:46:20,392 TRACE [org.xnio.nio] (default I/O-6) Cancelling key channel=java.nio.channels.SocketChannel[connected ishut local=ci-vm-10-0-151-92.hosted.upshift.rdu2.redhat.com/10.0.151.92:8080 remote=/10.0.151.93:43056], selector=sun.nio.ch.EPollSelectorImpl@41422a92, interestOps=4, readyOps=5 of java.nio.channels.SocketChannel[connected ishut local=ci-vm-10-0-151-92.hosted.upshift.rdu2.redhat.com/10.0.151.92:8080 remote=/10.0.151.93:43056] (same thread)
2023-12-15 16:46:20,395 TRACE [org.xnio.nio] (default I/O-6) Added task org.xnio.nio.NioTcpServerHandle$1@1a60e22e
2023-12-15 16:46:20,395 TRACE [org.xnio.listener] (default I/O-6) Invoking listener io.undertow.server.AbstractServerConnection$CloseSetter@3a80fb24 on channel org.xnio.nio.NioSocketStreamConnection@6c0d3798
2023-12-15 16:46:20,395 TRACE [org.xnio.listener] (default I/O-6) Invoking listener org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener@bf851f2 on channel ConduitStreamSinkChannel reading from io.undertow.conduits.WriteTimeout
StreamSinkConduit@140f3203
2023-12-15 16:46:20,399 ERROR [stderr] (default I/O-6) java.nio.channels.ClosedChannelException
2023-12-15 16:46:20,399 ERROR [stderr] (default I/O-6)  at java.base/sun.nio.ch.SocketChannelImpl.ensureOpenAndConnected(SocketChannelImpl.java:180)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:483)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at org.jboss.xnio.nio@3.8.13.Final-SNAPSHOT//org.xnio.nio.NioSocketConduit.internalWrite(NioSocketConduit.java:259)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at org.jboss.xnio.nio@3.8.13.Final-SNAPSHOT//org.xnio.nio.NioSocketConduit.write(NioSocketConduit.java:239)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at org.jboss.xnio@3.8.13.Final-SNAPSHOT//org.xnio.conduits.AbstractStreamSinkConduit.write(AbstractStreamSinkConduit.java:110)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at io.undertow.core@2.3.11.Final-SNAPSHOT//io.undertow.conduits.WriteTimeoutStreamSinkConduit.write(WriteTimeoutStreamSinkConduit.java:124)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at org.jboss.xnio@3.8.13.Final-SNAPSHOT//org.xnio.conduits.ConduitStreamSinkChannel.write(ConduitStreamSinkChannel.java:217)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at org.jboss.remoting@5.0.27.Final-redhat-00001//org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener.handleEvent(RemoteConnection.java:276)
2023-12-15 16:46:20,400 ERROR [stderr] (default I/O-6)  at org.jboss.remoting@5.0.27.Final-redhat-00001//org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener.handleEvent(RemoteConnection.java:243)
2023-12-15 16:46:20,408 ERROR [stderr] (default I/O-6)  at org.jboss.xnio@3.8.13.Final-SNAPSHOT//org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
2023-12-15 16:46:20,408 ERROR [stderr] (default I/O-6)  at org.jboss.xnio@3.8.13.Final-SNAPSHOT//org.xnio.conduits.WriteReadyHandler$ChannelListenerHandler.writeReady(WriteReadyHandler.java:65)
2023-12-15 16:46:20,408 ERROR [stderr] (default I/O-6)  at org.jboss.xnio.nio@3.8.13.Final-SNAPSHOT//org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:105)
2023-12-15 16:46:20,408 ERROR [stderr] (default I/O-6)  at org.jboss.xnio.nio@3.8.13.Final-SNAPSHOT//org.xnio.nio.WorkerThread.run(WorkerThread.java:603)

      The full file where this log was taken from is attached, and this bug was found as the first error to show up in the log when investigating WFLY-18700.

        1. server1.log.zip
          43.30 MB

            ropalka Richard Opalka
            flaviarnn Flavia Rainone
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: