Bug 54939 - No useful logging when maxHeaderCount hit
No useful logging when maxHeaderCount hit
Status: RESOLVED FIXED
Product: Tomcat 7
Classification: Unclassified
Component: Connectors
7.0.39
All All
: P2 normal (vote)
: ---
Assigned To: Tomcat Developers Mailing List
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2013-05-08 14:21 UTC by Eric Dalquist
Modified: 2014-02-17 13:50 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Eric Dalquist 2013-05-08 14:21:16 UTC
Recent versions of tomcat 6 & 7 added the maxHeaderCount parameter to the connector configuration with a default value of 100. When this limit is hit Tomcat returns a HTTP 400 response with a blank page and in the default configuration nothing is logged by the server. The org.apache.coyote.ajp.AjpProcessor class logs the error at DEBUG level but that doesn't get written anywhere using the default configuration.

The use case for more than 100 headers is the use of SSO systems that provide user attributes via HTTP headers. The Internet2 Shibboleth project is one good example, it is quite common to have well over 100 headers getting passed to Tomcat when using these systems.

I'd like to propose one of the following fixes:

- Write a message to the response explaining why the 400 response was returned. This would make it much easier for application deployers to determine the cause of the non-functional application.

- Have a default logger setup for the AJP connector and change the log level to INFO. Perhaps this gets treated as a one time warning and the first request that hits this limit is logged as WARN and the subsequent requests are logged at DEBUG to avoid log clutter.

- Increase the default value of maxHeaderCount to 1000 which would more easily accommodate the use of HTTP headers to pass user attributes.



I'd be happy to provide a patch for any of these solutions or other proposed ideas.
Comment 1 Christopher Schultz 2013-05-08 16:19:02 UTC
An IllegalStateException should be thrown in this case. Are you not seeing that in any log? I would expect IllegalStateException to propagate back to the error page including a stack trace, etc. Is that not happening?
Comment 2 Eric Dalquist 2013-05-08 16:34:53 UTC
The IllegalStateException is getting thrown but the try/catch that handles it sets the response to 400, logs the request and sets an error flag. No stack trace shows up in any log or on the rendered response.

See:
http://svn.apache.org/viewvc/tomcat/tc7.0.x/tags/TOMCAT_7_0_39/java/org/apache/coyote/ajp/AjpProcessor.java?revision=1459741&view=markup#l177

prepareRequest(); is the call that results in the IllegalStateException which is handled by the catch block starting at line 178. The exception is logged but at DEBUG level and to a logger that has no logging configuration in the default configuration.
Comment 3 Christopher Schultz 2013-05-09 01:14:49 UTC
Hmm. Sounds like using a new kind of exception type is appropriate: that could be logged specially. I wonder why Adapter.log() isn't actually logging anything...
Comment 4 Eric Dalquist 2013-05-09 01:17:57 UTC
Adapter.log() logs the request so you see an entry in the localhost_access log that looks like:

128.104.17.46 - - [07/May/2013:15:50:44 -0500] "GET /portal/layout.json HTTP/1.1" 400 -

That doesn't really give you any more information than what you see in the browser though.



Is this something you'd be interested in seeing an external patch for? If you have some ideas on how you'd like to see it fixed I could take a pass at implementation.
Comment 5 Mark Thomas 2013-05-28 09:53:46 UTC
Great. Here are some (short) pointers.

1. Patches should be against https://svna.apache.org/repos/asf/tomcat/trunk and attached to this issue in "diff -u" format

2. o.a.tomcat.util.log.UserDataHelper is the way to handle this. Use it in the catch (Throwable t) block in AbstractHttp11Processor

Look at how UserDataHelper is used elsewhere for examples on how to use it.

Ask on the dev list if you need help.
Comment 6 Mark Thomas 2013-06-04 12:55:28 UTC
I'd like to see this issue resolved for the 7.0.41 so I will be fixing it shortly.
Comment 7 Mark Thomas 2013-06-04 13:43:53 UTC
This has been fixed in trunk and 7.0.x and will be included in 7.0.41 onwards.