Bug 63182 - Servlet 3.1 ReadListener.onDataAvailable being invoked by the container even ServletInputStream.isReady returns true, when NIO2 connector being used and the read operation performed outside the onDataAvailable method.
Summary: Servlet 3.1 ReadListener.onDataAvailable being invoked by the container even ...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 8
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 8.5.38
Hardware: PC All
: P2 normal (vote)
Target Milestone: ----
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-02-16 15:28 UTC by xaxis0
Modified: 2019-03-03 23:32 UTC (History)
0 users



Attachments
Test case for this report (1.84 KB, application/x-zip-compressed)
2019-02-17 09:09 UTC, xaxis0
Details

Note You need to log in before you can comment on or make changes to this bug.
Description xaxis0 2019-02-16 15:28:57 UTC
using the following code can reproduce the error, with large size post request.

ServletInputStream in = req.getInputStream();
			in.setReadListener(new ReadListener() {

				@Override
				public void onError(Throwable t) {
					System.out.println("error: " + t);
					d.resolve(null);
				}

				int count = 0;

				@Override
				public void onDataAvailable() throws IOException {
					System.out.println("onDataAvailable");
					int c = in.read(new byte[1024]);
					System.out.println("read: " + c);
					if (c > 0) {
						count += c;
						System.out.println("\t\t\t\ttotal: " + MessageFormat.format("{0,number,#,##0}", count));
					}
					boolean ready = in.isReady();
					System.out.println("ready after: " + ready);
					if (ready) {
						onDataAvailable();
					}
				}

				@Override
				public void onAllDataRead() throws IOException {
					System.out.println("all read");
					d.resolve(null);
				}
			});

Console output sample:
...
...
ready after: true
onDataAvailable
read: 1024
                                total: 21,050,368
ready after: true
onDataAvailable
read: 1024
2019-02-16 23:27:09,654 ERROR com.webclient.web.LoginForm$3$1.run:444 - java.lang.IllegalStateException: In non-blocking mode you may not read from the ServletInputStream until the previous read has completed and isReady() returns true
java.lang.IllegalStateException: In non-blocking mode you may not read from the ServletInputStream until the previous read has completed and isReady() returns true
        at org.apache.catalina.connector.CoyoteInputStream.checkNonBlockingRead(CoyoteInputStream.java:287)
        at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:128)
Comment 1 xaxis0 2019-02-16 15:31:00 UTC
the bug only happen when protocol="org.apache.coyote.http11.Http11Nio2Protocol", i.e. the code work fine when protocol="org.apache.coyote.http11.Http11NioProtocol" being used
Comment 2 xaxis0 2019-02-16 15:40:57 UTC
Also if the code dosen't start a new thread to do the read operation, everything got fine. e.g.

@Override
public void onDataAvailable() throws IOException {
	System.out.println("onDataAvailable");
	int c = in.read(new byte[1024]);
	System.out.println("read: " + c);
	if (c > 0) {
		count += c;
		System.out.println("\t\t\t\ttotal: " + MessageFormat.format("{0,number,#,##0}", count));
	}
	boolean ready = in.isReady();
	System.out.println("ready after: " + ready);
	if (ready) {
		onDataAvailable();
	}
}
Comment 3 Remy Maucherat 2019-02-16 19:25:46 UTC
Please provide the test case and details for the problem as your last comment does not match the code given.

Note that we have virtually the exact same code and test case in the Tomcat testsuite (as far as the portion given is concerned), so what you have given is not enough to investigate further: org.apache.catalina.nonblocking.TestNonBlockingAPI.testNonBlockingRead
Comment 4 xaxis0 2019-02-17 09:09:35 UTC
Created attachment 36439 [details]
Test case for this report

attached the test case, including the servlet, client and the web.xml.

also, the console output sample, please check out the line after '>>>>>>>>>>>>>>>>>>>>>>', which indicate the container will invoke the ondataavailable method while is ready returning true, which is not correct:

ready after: true
onDataAvailable: from non container thread, because isready return true, after read
read: 1017
                                total: 3,132,935
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
read: 1024
                                total: 3,133,959
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
read: 728
                                total: 3,134,687
onDataAvailable: from container thread
ready after: false
onDataAvailable: from container thread
read: 289
                                total: 3,134,976

>>>>>>>>>>>>>>>>>>>>>>
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
read: 1024
onDataAvailable: from container thread
                                total: 3,136,000
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
read: 1017
                                total: 3,137,017
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
read: 1024
read: 1024
read: 1017
                                total: 3,140,082
                                total: 3,139,065
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
                                total: 3,138,041
ready after: true
ready after: true
onDataAvailable: from non container thread, because isready return true, after read
onDataAvailable: from non container thread, because isready return true, after read
read: 1017
                                total: 3,141,099org.apache.catalina.connector.ClientAbortException: java.io.IOException: Invalid end of line sequence (character other than CR or LF found)

read: 1024      at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:348)

ready after: true
onDataAvailable: from non container thread, because isready return true, after read
        at org.apache.catalina.connector.InputBuffer.checkByteBufferEof(InputBuffer.java:663)
Comment 5 xaxis0 2019-02-17 09:11:06 UTC
P.S. the happen only for nio2 connector, i.e. protocol="org.apache.coyote.http11.Http11Nio2Protocol" in server.xml
Comment 6 Remy Maucherat 2019-02-18 13:54:19 UTC
The bugzilla is properly entered, you don't need to ping about it or update it anymore.

That being said, the pattern used is at best inefficient, unlike writes where it can have uses.
Comment 7 Remy Maucherat 2019-03-03 23:32:16 UTC
The fix will be in Tomcat 9.0.17 and 8.5.39.