It would need to be more reproduceable than this, and it probably means what it means (there's a concurrent write) unless there's a glitch setting back the pending flag, which seems doubtful. Something worth testing is dropping SSL to compare with the vanilla NIO2 code.

There are no such problems when dropping SSL.

As part of the investigation I fixed some issues (r1672297) which will be backported to Tomcat 8, but I don't see any way for the read pending flag to have a bad state. Without some test, the issue will eventually be closed.

(In reply to Remy Maucherat from comment #3)
> As part of the investigation I fixed some issues (r1672297)

Thanks for your initial look and your changes. These changes do not fix the problem (I built and dropped tomcat-coyote.jar into 8.0.15). The code I'm running is proprietary and I've not even read it yet. I will try to provide a sufficient test case if/when I have time.

It probably still works at the moment, but I don't think that's the right way to test with all the connector refactorings in trunk.

If you're building from source, you can remove the exception throw and see if it works without issues or corruption. I don't see how the flag can be wrong at the moment though, so it could be a timing issue this connector triggers.

Unrelated (but useful) fixes merged in Tomcat 8 as r1672626.

(In reply to Remy Maucherat from comment #6)
> Unrelated (but useful) fixes merged in Tomcat 8 as r1672626.

I exported from ^/trunk@1672808, removed both "throw ReadPendingException" from SecureNio2Channel, built, installed tomcat-coyote.jar. I get a different "Caused by":

Caused by: java.nio.channels.ReadPendingException
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(Unknown Source)
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(Unknown Source)
	at org.apache.tomcat.util.net.SecureNio2Channel$FutureRead.<init>(SecureNio2Channel.java:484)
	at org.apache.tomcat.util.net.SecureNio2Channel.read(SecureNio2Channel.java:582)
	at org.apache.coyote.http11.InternalNio2InputBuffer.fill(InternalNio2InputBuffer.java:223)
	at org.apache.coyote.http11.InternalNio2InputBuffer$SocketInputBuffer.doRead(InternalNio2InputBuffer.java:331)
	at org.apache.coyote.http11.filters.ChunkedInputFilter.readBytes(ChunkedInputFilter.java:320)
	at org.apache.coyote.http11.filters.ChunkedInputFilter.parseChunkHeader(ChunkedInputFilter.java:350)
	at org.apache.coyote.http11.filters.ChunkedInputFilter.doRead(ChunkedInputFilter.java:190)
	at org.apache.coyote.http11.AbstractInputBuffer.doRead(AbstractInputBuffer.java:416)
	at org.apache.coyote.Request.doRead(Request.java:469)
	at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:338)
	at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:395)
	at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:363)
	at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:190)
	at sun.nio.cs.StreamDecoder.readBytes(Unknown Source)

So the pending flag seems correct. The difference with non SSL is thus unexplained, and this needs a (simple) testcase.

Also, testing on Tomcat trunk may not be useless.

Waiting on a test case to reproduce this. Without a test case - or at least steps to reproduce - this bug will eventually get closed as WORKSFORME.

(In reply to Remy Maucherat from comment #9)
> Also, testing on Tomcat trunk may not be useless.

Same errors with Tomcat 8.0.21. When I build/run /trunk@1675728, I get:

23-Apr-2015 17:55:46.105 INFO [http-nio2-8443-exec-3] org.apache.coyote.http11.AbstractHttp11Processor.process Error parsing HTTP request header
 Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
23-Apr-2015 17:55:46.403 WARNING [http-nio2-8443-exec-8] org.apache.tomcat.util.net.AbstractEndpoint.countDownConnection Incorrect connection count, multiple socket.close called on the same socket.
23-Apr-2015 17:55:50.130 WARNING [http-nio2-8443-exec-2] org.apache.tomcat.util.net.AbstractEndpoint.countDownConnection Incorrect connection count, multiple socket.close called on the same socket.
23-Apr-2015 17:55:50.131 WARNING [http-nio2-8443-exec-1] org.apache.tomcat.util.net.AbstractEndpoint.countDownConnection Incorrect connection count, multiple socket.close called on the same socket.

Since there's no test case, it is worth retesting again [with trunk] since the previous fix caused a regression.

Any update now 8.0.23 is released? Still waiting on a test case or steps to reproduce.

Created attachment 32830 [details]
Exceptions

Retested and reconfirmed problem with /trunk@1685924. Attached exceptions.

Without a relatively simple test case, I think this should be closed for the time being. There has to be some concurrency involved and the framework really gets in the way.

(In reply to Remy Maucherat from comment #16)
> Without a relatively simple test case, I think this should be closed for the
> time being. There has to be some concurrency involved and the framework
> really gets in the way.

That is effectively what the NEEDINFO state does. When I do a release I aim to fix all the open bugs that affect that version excluding any in the NEEDINFO state.

I'd prefer a simple test case but right now I'd take any test case that reproduced this issue fairly reliably.

Without a test case this is going to sit in the NEEDINFO state.

> Without a test case this is going to sit in the NEEDINFO state.

Understandable. Regardless of whether there is a test case, there is a bug causing exceptions in Tomcat 8 latest. I may not be the only one who can contribute to its resolution. You're asking me to search through an unfamiliar codebase for a closed-source commercial client which likely uses Windows and SOAP API's that I'm also unfamiliar with, and extract a test case that I feel comfortable sharing. Sadly I have little desire to learn much about this client. I do wish to help the Tomcat community and will try to find the time.

We are running into this same issue in our application and I just started to debug the problem. The one additional piece of information I can add is that I only get this error when I have SSL enabled in the connector and the SOAP client connects via HTTPS.  If I use HTTP only, this issue doesn't occur.

(In reply to Robert M from comment #19)
> We are running into this same issue in our application and I just started to
> debug the problem. The one additional piece of information I can add is that
> I only get this error when I have SSL enabled in the connector and the SOAP
> client connects via HTTPS.  If I use HTTP only, this issue doesn't occur.

While that isn't new information (see comment #2) another user being able to replicate the issue does increase the chances of being able to generate a reproducible test case. Anything you can do in that direction would be appreciated.

This could use another trunk retest.

Investigating another issue, it seems possible this one is caused by a timeout exception that gets swallowed, followed by a new read attempt. It is not really a Tomcat bug if the theory is correct.

In trunk, I added a cancel of the blocking read/write in case a timeout occurs, but it could cause a loop and the connection to stay active forever: a Servlet is not supposed to catch exceptions.

(In reply to Remy Maucherat from comment #21)
> This could use another trunk retest.


Built, ran /trunk@1711357. Client now throws exception connected to non-SSL port too...

2015-10-29 16:44:58,287 exception [Thread-23] - ... -  javax.xml.ws.soap.SOAPFaultException: Couldn't create SOAP message due to exception: java.nio.channels.ReadPendingException
	at com.sun.xml.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:193)
	at com.sun.xml.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:126)
	at com.sun.xml.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:123)
	at com.sun.xml.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:93)
	at com.sun.xml.ws.client.sei.SEIStub.invoke(SEIStub.java:144)


Tomcat server exception in catalina.out...

29-Oct-2015 16:44:58.122 SEVERE [http-nio2-8080-exec-7] com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle Couldn't create SOAP message due to exception: java.nio.channels.ReadPendingException
 com.sun.xml.ws.protocol.soap.MessageCreationException: Couldn't create SOAP message due to exception: java.nio.channels.ReadPendingException
	at com.sun.xml.ws.encoding.SOAPBindingCodec.decode(SOAPBindingCodec.java:363)
	at com.sun.xml.ws.transport.http.HttpAdapter.decodePacket(HttpAdapter.java:336)
	at com.sun.xml.ws.transport.http.HttpAdapter.access$400(HttpAdapter.java:96)
	at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:591)
	at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:259)
	at com.sun.xml.ws.transport.http.servlet.ServletAdapter.invokeAsync(ServletAdapter.java:213)
	at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:159)
	at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:194)
	at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:80)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:218)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:616)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:673)
	at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.doRun(Nio2Endpoint.java:1074)
	at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.run(Nio2Endpoint.java:1033)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.nio.channels.ReadPendingException
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(Unknown Source)
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(Unknown Source)
	at org.apache.tomcat.util.net.Nio2Channel.read(Nio2Channel.java:133)
	at org.apache.coyote.http11.InternalNio2InputBuffer.fill(InternalNio2InputBuffer.java:225)
	at org.apache.coyote.http11.InternalNio2InputBuffer$SocketInputBuffer.doRead(InternalNio2InputBuffer.java:336)
	at org.apache.coyote.http11.filters.ChunkedInputFilter.readBytes(ChunkedInputFilter.java:320)
	at org.apache.coyote.http11.filters.ChunkedInputFilter.parseChunkHeader(ChunkedInputFilter.java:350)
	at org.apache.coyote.http11.filters.ChunkedInputFilter.doRead(ChunkedInputFilter.java:190)
	at org.apache.coyote.http11.AbstractInputBuffer.doRead(AbstractInputBuffer.java:416)
	at org.apache.coyote.Request.doRead(Request.java:469)
	at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:342)
	at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:395)
	at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:367)
	at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:190)
	at sun.nio.cs.StreamDecoder.readBytes(Unknown Source)
	at sun.nio.cs.StreamDecoder.implRead(Unknown Source)
	at sun.nio.cs.StreamDecoder.read(Unknown Source)
	at java.io.InputStreamReader.read(Unknown Source)
	at com.ctc.wstx.io.MergedReader.read(MergedReader.java:105)
	at com.ctc.wstx.io.ReaderSource.readInto(ReaderSource.java:87)
	at com.ctc.wstx.io.BranchingReaderSource.readInto(BranchingReaderSource.java:57)
	at com.ctc.wstx.sr.StreamScanner.loadMore(StreamScanner.java:988)
	at com.ctc.wstx.sr.StreamScanner.getNext(StreamScanner.java:754)
	at com.ctc.wstx.sr.BasicStreamReader.nextFromTree(BasicStreamReader.java:2676)
	at com.ctc.wstx.sr.BasicStreamReader.next(BasicStreamReader.java:1050)
	at com.sun.xml.ws.util.xml.XMLStreamReaderFilter.next(XMLStreamReaderFilter.java:96)
	at com.sun.xml.ws.streaming.XMLStreamReaderUtil.next(XMLStreamReaderUtil.java:80)
	at com.sun.xml.ws.streaming.XMLStreamReaderUtil.nextContent(XMLStreamReaderUtil.java:114)
	at com.sun.xml.ws.streaming.XMLStreamReaderUtil.nextElementContent(XMLStreamReaderUtil.java:104)
	at com.sun.xml.ws.encoding.StreamSOAPCodec.decode(StreamSOAPCodec.java:234)
	at com.sun.xml.ws.encoding.StreamSOAPCodec.decode(StreamSOAPCodec.java:307)
	at com.sun.xml.ws.encoding.StreamSOAPCodec.decode(StreamSOAPCodec.java:133)
	at com.sun.xml.ws.encoding.SOAPBindingCodec.decode(SOAPBindingCodec.java:358)
	... 30 more

Hum, it's not trunk, it's branch 8 head. Anyway, the SSL thing was just coincidental, never mind.

It would be nice in the channel read to capture the previous stack trace (throw and catch an exception, put it in a field, then catch the ReadPendingException and print the saved one).

When I say in the channel read, I mean here for the debug code:
 org.apache.tomcat.util.net.Nio2Channel.read(Nio2Channel.java:133)

Created attachment 33234 [details]
Debug code

If the exception does not occur, the code can be added to SecureNio2Channel.

Created attachment 33240 [details]
Client exceptions for /trunk@1711734

Thanks for the patch! I exported, applied, built, ran.

Created attachment 33241 [details]
Server exceptions for /trunk@1711734 with debug code

Thanks for the patch! I exported, applied, built, ran.

The debug info is not there however.

Created attachment 33242 [details]
stderr for /trunk@1711734 with debug code

Previous attachment was catalina.out. stdout has only:

> Read pending http-nio2-8080-exec-9

stderr is attached here.

Created attachment 33243 [details]
Fixed debug code

The previous one was bad, and also this puts the info in the log file.

Created attachment 33244 [details]
Server exceptions for /trunk@1711734 with debug code

> (In reply to Remy Maucherat from comment #31)

Cleaned, applied patch from c#31, built, ran.

Ok, so this looks like legacy blocking code, which calls available() to be smart.

Then it breaks because the input stream's available is really meant to be used with isReady now (Servlet 3.1) and does a real async read. So maybe the available action could use an added optional boolean parameter and do the async read only if it is true (which would indicate Servlet 3.1 mode).

Created attachment 33247 [details]
Test patch

With debug.

(In reply to Remy Maucherat from comment #34)
> Created attachment 33247 [details]
> Test patch
> 
> With debug.

Excellent, this patch has resolved the problem. I tested both HTTP and HTTPS. I see no exceptions in the logs and my client works as expected. Thanks for your help.

The fix will be in 8.0.29, committed as r1712081. You should drop your test patch since the debug exception will impact performance. Thanks for the testing.