Bug 51912 - IOOB exception in InternalNioInputBuffer when debug logging is enabled
Summary: IOOB exception in InternalNioInputBuffer when debug logging is enabled
Alias: None
Product: Tomcat 7
Classification: Unclassified
Component: Connectors (show other bugs)
Version: 7.0.22
Hardware: PC Windows XP
: P2 normal (vote)
Target Milestone: ---
Assignee: Tomcat Developers Mailing List
Depends on:
Reported: 2011-09-28 14:22 UTC by Konstantin Kolinko
Modified: 2013-07-31 14:57 UTC (History)
0 users


Note You need to log in before you can comment on or make changes to this bug.
Description Konstantin Kolinko 2011-09-28 14:22:54 UTC
I encountered the following while testing 7.0.22 RC.

To reproduce:
1. Replace conf/logging.properties with the following:
handlers = 1catalina.org.apache.juli.FileHandler
.handlers = 1catalina.org.apache.juli.FileHandler

1catalina.org.apache.juli.FileHandler.level = FINE
1catalina.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
1catalina.org.apache.juli.FileHandler.prefix = catalina.

Note that level=FINE enables debug logging.

2. Run testsuite for NIO + org.apache.coyote.http11.TestInternalInputBuffer
by adding the following to build.properties:

3. The test fails:
Testsuite: org.apache.coyote.http11.TestInternalInputBuffer
Tests run: 7, Failures: 2, Errors: 0, Time elapsed: 50,357 sec

Testcase: testBug48839 took 9,594 sec
Testcase: testBug51557NoColon took 1,217 sec

	at org.apache.coyote.http11.TestInternalInputBuffer.testBug51557NoColon(TestInternalInputBuffer.java:137)

Testcase: testBug51557Separators took 22,807 sec
Testcase: testBug51557Ctl took 13,104 sec

	at org.apache.coyote.http11.TestInternalInputBuffer.doTestBug51557Char(TestInternalInputBuffer.java:216)
	at org.apache.coyote.http11.TestInternalInputBuffer.testBug51557Ctl(TestInternalInputBuffer.java:160)

Testcase: testBug51557Continuation took 1,248 sec
Testcase: testBug51557BoundaryStart took 1,185 sec
Testcase: testBug51557BoundaryEnd took 1,186 sec

4. It is the only test in testsuite that is failing in this logging configuration. The rest of testsuite did run successfully.
This test also succeeds when it is run with BIO or APR. Only NIO fails.

In the log file the following exception occurs 3 times:
28.09.2011 17:50:38 org.apache.coyote.http11.AbstractHttp11Processor process
FINE: Error parsing HTTP request header
java.lang.StringIndexOutOfBoundsException: String index out of range: -40
	at java.lang.String.checkBounds(String.java:397)
	at java.lang.String.<init>(String.java:482)
	at org.apache.coyote.http11.InternalNioInputBuffer.skipLine(InternalNioInputBuffer.java:672)
	at org.apache.coyote.http11.InternalNioInputBuffer.parseHeader(InternalNioInputBuffer.java:526)
	at org.apache.coyote.http11.InternalNioInputBuffer.parseHeaders(InternalNioInputBuffer.java:435)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:905)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:515)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1550)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)

It is caused by debug logging in

671        if (log.isDebugEnabled()) {
672            log.debug(sm.getString("iib.invalidheader", new String(buf,
673                    headerData.start,
674                    headerData.lastSignificantChar - headerData.start + 1,
675                    DEFAULT_CHARSET)));
676        }

InternalInputBuffer and InternalAprInputBuffer have similar debug logging in their skipLine() methods, but they do not fail.
Comment 1 Konstantin Kolinko 2011-09-29 10:35:20 UTC
Fixed in trunk and 7.0.x (r1177256) and will be in 7.0.23.

Reassigning to Tomcat 6, as I think its InternalNioInputBuffer.parseHeader should be aligned with TC7.
Comment 2 Mark Thomas 2012-06-21 08:43:49 UTC
It has been almost nine months. Are you going to propose a patch for this? If not, lets close this as fixed in 7.0.x.
Comment 3 Mark Thomas 2013-07-31 14:57:05 UTC
No proposal was forthcoming for 6.0.x