Bug 46907 - Jasper with log4j in web-app classpath and debug level enabled prevents reading HTTP POST stream from JSP
Jasper with log4j in web-app classpath and debug level enabled prevents readi...
Product: Tomcat 5
Classification: Unclassified
Component: Jasper
PC Windows XP
: P2 major (vote)
: ---
Assigned To: Tomcat Developers Mailing List
Depends on:
  Show dependency tree
Reported: 2009-03-24 15:20 UTC by Olivier Lau
Modified: 2009-08-12 04:51 UTC (History)
0 users

test application. I try to reproduce bug with it (9.47 KB, application/zip)
2009-04-06 04:33 UTC, IzhikovNikolay
web archive reproducing #46907 (384.84 KB, application/octet-stream)
2009-04-08 05:49 UTC, Olivier Lau

Note You need to log in before you can comment on or make changes to this bug.
Description Olivier Lau 2009-03-24 15:20:17 UTC
This is on Tomcat 5.5.x (don't remember the last rev. number, not my current machine).

When log4j is in the classpath of the web-app and is configured to log at debug level, Jasper dumps the whole HTTP POST request body as debug traces. This consumes the HttpServletRequest input stream which then arrives unusable for the user at the beginning of the JSP code (using  HttpServletRequest.getInputStream(), the stream is already at its end).
A workaround is to disable debug traces for Japser class in log4j.properties, but Jasper should not consume the HttpServletRequest input stream whatever mode it runs into.
Comment 1 Olivier Lau 2009-03-25 01:17:56 UTC
this is on tomcat 5.5.26
Comment 2 IzhikovNikolay 2009-04-06 03:17:08 UTC
I will investigate this bug and fix it if I needed
Comment 3 IzhikovNikolay 2009-04-06 04:33:44 UTC
Created attachment 23445 [details]
test application. I try to reproduce bug with it

I can't reproduce problem with attached test application.
I test it with tomcat builded from this url

Can you provide test application and log file to reproduce problem
Comment 4 IzhikovNikolay 2009-04-06 04:34:45 UTC
Can't reproduce bug with test application
Comment 5 Olivier Lau 2009-04-08 05:49:03 UTC
Created attachment 23461 [details]
web archive reproducing #46907
Comment 6 Olivier Lau 2009-04-08 05:50:21 UTC
Attached .war file (test_log4j.war, sources included) demonstrating the problem.
Please note the presence of commons-logging into /web-inf/lib, as without this Tomcat would not issue any log, and therefore the problem would not be reproduced.

- run the provided webapp under tomcat 5.5.26 (problem may exist on more recent versions too) on a given host (ex: localhost)
- perform an HTTP POST with body data on http://localhost/testlog4j/post.jsp
(with curl: curl -d "name=value" http://localhost/testlog4j/post.jsp)
- if things would work, the jsp would return the content of the POST body, but it doesn't, because Jasper consumes the request stream with its debug traces before the JSP is called.
- to make it work, disable Jasper debug logging: edit /web-inf/classes/log4j.properties and uncomment the "log4j.category.org.apache.jasper.servlet.JspServlet=WARN" line : this way Jasper will not log anymore debug traces, therefore not consuming the stream the JSP is using.
Comment 7 IzhikovNikolay 2009-04-09 04:12:48 UTC
Ok. I take a look.
Comment 8 Kirk True 2009-04-16 08:18:00 UTC
I was able to reproduce this with 5.5.26 (the OP's stated version) and 5.5.27 (the current latest 5.5.x version). However, versions 6.0.0-alpha through to 6.0.18 (the current latest 6.0.x version) as well as the trunk do not exhibit this behavior.

So a question for the Tomcat developers, do we want to fix this for 5.5.x or do we instead suggest the user upgrade?
Comment 9 Mark Thomas 2009-04-16 08:21:16 UTC
It will depend what the patch looks like. Create a patch and one of us will take a look. If the patch is OK, we'll propose it for 5.5.x.
Comment 10 IzhikovNikolay 2009-04-17 03:00:59 UTC
I still can't reproduce the bug.
I'm on WindowsXP 
jdk - 1.6.0_07
Comment 11 Kirk True 2009-04-17 09:03:24 UTC
I should mention I'm on Linux (Fedora 10 x64). Here's my java -version:

    java version "1.6.0_12"
    Java(TM) SE Runtime Environment (build 1.6.0_12-b04)
    Java HotSpot(TM) 64-Bit Server VM (build 11.2-b01, mixed mode)
Comment 12 Mark Thomas 2009-07-23 23:18:42 UTC
I have removed the debug logging (of the request parameters) that caused the input stream to be consumed in trunk. The patch has been proposed for 5.5.x and 6.0.x.
Comment 13 Mark Thomas 2009-08-12 04:36:39 UTC
The patch has been applied to 5.5.x and will be included in 5.5.29 onwards.
Comment 14 Mark Thomas 2009-08-12 04:51:38 UTC
This has been fixed in 6.0.x and will be included in 6.0.21 onwards.