Bug 53697 - java.lang.NullPointerException at org.apache.coyote.http11.Http11AprProcessor.actionInternal(Http11AprProcessor.java:277)
Summary: java.lang.NullPointerException at org.apache.coyote.http11.Http11AprProcessor...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 7
Classification: Unclassified
Component: Connectors (show other bugs)
Version: 7.0.29
Hardware: HP Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
: 56201 (view as bug list)
Depends on:
Blocks:
 
Reported: 2012-08-11 08:33 UTC by lacycb
Modified: 2014-02-28 21:09 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description lacycb 2012-08-11 08:33:54 UTC
I hit tomcat with ~20 different urls in ~2 seconds, test some functionality, wait ~3 minutes, then do it again and I always get this exception and then I get (intermitent) connection interrupted messages in the browser.  Here's the full trace:

Aug 10, 2012 6:33:14 PM org.apache.catalina.connector.CoyoteAdapter event
SEVERE: null
Aug 10, 2012 6:33:14 PM org.apache.catalina.connector.CoyoteAdapter event
java.lang.NullPointerException
	at org.apache.coyote.http11.Http11AprProcessor.actionInternal(Http11AprProcessor.java:277)
	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:846)
	at org.apache.coyote.Response.action(Response.java:172)
	at org.apache.catalina.connector.CoyoteAdapter.event(CoyoteAdapter.java:229)
	at org.apache.coyote.http11.Http11AprProcessor.event(Http11AprProcessor.java:133)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:581)
	at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1770)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)

Aug 10, 2012 6:33:14 PM org.apache.coyote.http11.Http11AprProcessor event
SEVERE: Error processing request
java.lang.NullPointerException
	at org.apache.coyote.http11.Http11AprProcessor.actionInternal(Http11AprProcessor.java:277)
	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:846)
	at org.apache.coyote.Request.action(Request.java:346)
	at org.apache.catalina.connector.Request.getRemoteAddr(Request.java:1281)
	at org.apache.catalina.connector.Request.getRemoteHost(Request.java:1296)
	at org.apache.catalina.valves.AccessLogValve$HostElement.addElement(AccessLogValve.java:1327)
	at org.apache.catalina.valves.AccessLogValve.log(AccessLogValve.java:953)
	at org.apache.catalina.core.AccessLogAdapter.log(AccessLogAdapter.java:51)
	at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1263)
	at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1270)
	at org.apache.catalina.connector.CoyoteAdapter.event(CoyoteAdapter.java:250)
	at org.apache.coyote.http11.Http11AprProcessor.event(Http11AprProcessor.java:133)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:581)
	at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1770)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)

Additional information:
 - hp Proliant DL360 with two 3ghz processors
 - CentOS 6.3
 - One app runs websockets under bleading edge Atmosphere and Grails
 - the 20 urls come from chrome and firefox, simulatneously
Comment 1 Mark Thomas 2012-08-11 19:59:16 UTC
Without a test case to reproduce the problem there is little the Tomcat developers can do. It looks like multiple threads are acting on the same socket at the same time. What I can't tell is if that is intentional, the result of a Tomcat bug or something the frameworks/app is doing.

The NPE is avoidable in one of the two stack traces provided but I am not yet sure avoiding it is a good thing (depending on the root cause).

I would add that a test case isn't essential - the Tomcat developers have made changes in the past for hard to reproduce bugs based purely on the bug reporters analysis of their code, the Tomcat code and what is going wrong where. That said, it is also the case that the Tomcat developers have refused to apply speculative patches that the bug reporter claims fixes the issue that did not come with an explanation of what the bug was and why the patch fixed it.
Comment 2 lacycb 2012-08-12 21:31:53 UTC
Please find the test case at:
https://chrislacy.net/downloads/tomcat-bug-53697.tar.gz

Steps:
- install apr and dependencies
- compile and install native
- startup tomcat (./startup.sh)
- hit https://localhost:8443/AtmosphereTest
- hit http://localhost:8080/AtmosphereTest
- repeat hits if necessary (usually first round does it, but sometimes
another hit to https is needed)

I used firefox and tested on both the server I mentioned and another
development box.  A second, related, error that happends ~1/2 of the time, is currently in catalina.out
and has the pid error file in CATALINA_HOME - copied here:

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007fd3840a78d0, pid=28351, tid=140546779842304
#
# JRE version: 7.0_05
# Java VM: OpenJDK 64-Bit Server VM (23.0-b21 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C  0x00007fd3840a78d0
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /home/chris/Documents/apache-tomcat-7.0.29/bin/hs_err_pid28351.log
#
# If you would like to submit a bug report, please include
# instructions on how to reproduce the bug and visit:
#   http://icedtea.classpath.org/bugzilla
#
Comment 3 Mark Thomas 2012-08-15 18:31:16 UTC
https://chrislacy.net/downloads/tomcat-bug-53697.tar.gz returns a 404 reponse

Without a test case that demonstrates the issue, this is going to get closed as wontfix.
Comment 4 lacycb 2012-08-15 19:05:17 UTC
Please try again.  Server overhaul yesterday evening took download down.
Comment 5 Mark Thomas 2012-08-15 20:59:00 UTC
I don't think a 43MB download could be classed as a minimal test case.

While it is true that having a complete copy of the entire Tomcat directory means we have all the config info we might ever need, normally the WAR would suffice.
Comment 6 Mark Thomas 2012-08-15 21:18:09 UTC
OK. I can reproduce this now. I'm not sure how long it will take to track down the root cause.
Comment 7 Mark Thomas 2012-08-15 22:56:47 UTC
Found it. It is a regression in the HTTP APR connector introduced by the fix for bug 51881. The isComet flag for instances of Http11AprProcessor (which gets re-used across connections) was not being reset in some circumstances so Tomcat was attempting to handle a new HTTP request using the Comet processing chain. Chaos ensued.

This has been fixed in trunk and 7.0.x and will be included in 7.0.30 onwards.
Comment 8 lacycb 2012-08-16 00:17:33 UTC
Testing now, but wanted to give you a quick thanks.
Comment 9 Konstantin Kolinko 2014-02-28 21:09:48 UTC
*** Bug 56201 has been marked as a duplicate of this bug. ***