You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by eurotrans-Verlag <ve...@t-online.de> on 2011/07/07 02:31:50 UTC
NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Hi all,
Im using Tomcat 7.0.16 on a system with Java 1.6.0_26 on Windows Serer 2008
and wondered about a strange NPE I got shortly after deploying a webapp to
Tomcat:
SCHWERWIEGEND: An exception or error occurred in the container during the
request processing
java.lang.NullPointerException
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja
va:287)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja
va:164)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase
.java:462)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164
)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100
)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java
:118)
at
org.apache.catalina.valves.CrawlerSessionManagerValve.invoke(CrawlerSessionM
anagerValve.java:172)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:403)
at
org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:284)
at
org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProt
ocol.java:146)
at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:
1730)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
va:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
08)
at java.lang.Thread.run(Thread.java:662)
>From looking at Tomcat 7.0.16's source, I can see that line 287 in
StandardWrapperValve is inside a catch block:
285 } catch (Throwable e) {
286 ExceptionUtils.handleThrowable(e);
287 container.getLogger().error(sm.getString(
288 "standardWrapper.serviceException", wrapper.getName(),
289 context.getName()), e);
290 throwable = e;
291 exception(request, response, e);
292 }
So does that mean that another Exception/Error occurred, but was suppressed
by that NPE and therefore couldn't be logged?
Regards,
Konstantin Preißer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Mark Thomas <ma...@apache.org>.
On 08/07/2011 22:25, eurotrans-Verlag wrote:
> Hi Christopher,
>
>>
>> The compiler must have gotten smarter than the last time I checked.
>>
>
> I'm sorry: I compiled that code with the Eclipse compiler. When compiling it with the Oracle Java compiler (javac), it prints out the line number of the "System.out.println".
> Maybe if Tomcat was compiled with the standard Java compiler, it could be that on the NPE at StandardWrapperValve.invoke(), also "context" was null, like in the NPE at StandardContextValve.invoke().
7.0.16 (assuming you downloaded the binary from the ASF) was built with
the 64-bit Windows Oracle JDK. You can check exactly which version by
looking at the manifest of any of the JARs.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by eurotrans-Verlag <ve...@t-online.de>.
Hi Christopher,
>
> The compiler must have gotten smarter than the last time I checked.
>
I'm sorry: I compiled that code with the Eclipse compiler. When compiling it with the Oracle Java compiler (javac), it prints out the line number of the "System.out.println".
Maybe if Tomcat was compiled with the standard Java compiler, it could be that on the NPE at StandardWrapperValve.invoke(), also "context" was null, like in the NPE at StandardContextValve.invoke().
>
> You could modify the source and add another dump of the original
> exception (say, to stdout). That way, if it does happen again, you'll
> at
> least see the root cause.
>
OK, I may try that. But I have never seen that NPE in StandardWrapperValve before I started this thread, so I don't think it is worth it (Tomcat 7 releases are every month, and I don't want to modify the code in each version). :)
>
> No, it sounds like that might be a rarely-seen bug in Tomcat since it
> happens only during context reload while a long-running request is in
> progress. If you can build a simple test case, attach it to a new BZ
> entry and we'll see about getting it fixed.
>
OK, Thanks.
Regards,
Konstantin Preißer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Konstantin,
On 7/8/2011 8:00 AM, eurotrans-Verlag wrote:
> After compiling and running it with the Oracle Java 1.6.0_26, the
> line number printed was the line with the "str.toLowerCase()", not
> the "System.out.println". So I assume the same is true for the
> compiled Tomcat, thus I supposed that only container or the logger
> could be null).
The compiler must have gotten smarter than the last time I checked.
>> Problem solved?
>
> Well, I don't know what the original problem was, so I don't know if
> it is solved. ;)
>
> My concern at the moment is not the original exception that occurred,
> but the NPE that suppressed that exception, because if it happens
> again, I will not able to see what was the original exception.
You could modify the source and add another dump of the original
exception (say, to stdout). That way, if it does happen again, you'll at
least see the root cause.
> As Pid said, it could have something to do with the old context which
> was still waiting for a request to finish, and as I stated in the
> other message, I could reproduce a NPE, but in
> StandardContextValve.invoke() (there "context" was null). But NPEs
> thrown are never good, are they?
No, it sounds like that might be a rarely-seen bug in Tomcat since it
happens only during context reload while a long-running request is in
progress. If you can build a simple test case, attach it to a new BZ
entry and we'll see about getting it fixed.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAk4XYHQACgkQ9CaO5/Lv0PDALACfZ/yeScY+U4SVV6+F8FnzQywT
ISUAnj7VQIbN60lUTnCdvOmQJfIBHITB
=SZ6S
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by eurotrans-Verlag <ve...@t-online.de>.
Hi Christopher,
>
> My experience with the Sun/Oracle compiler is that lines 288 and 289
> will never be indicated in a stack trace: the line number of the start
> of the statement is considered the line number for the entire
> statement.
Well, I made a small test program with this code:
String str = null;
System.out.println(
"blah" +
str.toLowerCase()
);
(note that the str.toLowerCase() which will throw a NPE is two lines below the System.out.println() call).
After compiling and running it with the Oracle Java 1.6.0_26, the line number printed was the line with the "str.toLowerCase()", not the "System.out.println". So I assume the same is true for the compiled Tomcat, thus I supposed that only container or the logger could be null).
>
> Problem solved?
>
Well, I don't know what the original problem was, so I don't know if it is solved. ;)
My concern at the moment is not the original exception that occurred, but the NPE that suppressed that exception, because if it happens again, I will not able to see what was the original exception.
As Pid said, it could have something to do with the old context which was still waiting for a request to finish, and as I stated in the other message, I could reproduce a NPE, but in StandardContextValve.invoke() (there "context" was null). But NPEs thrown are never good, are they?
Regards,
Konstantin Preißer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Konstantin,
On 7/7/2011 3:59 PM, eurotrans-Verlag wrote:
> Hi Christopher,
>
>> -----Original Message----- From: Christopher Schultz
>> [mailto:chris@christopherschultz.net] Sent: Thursday, July 07, 2011
>> 9:13 PM
>>
>> Looks like it. I would be very interested to know which of those
>> objects is null: the container, the logger, the wrapper, or the
>> context.
>>
>> - -chris
>
> I thought the same (I suppose only container or the logger can be
> null, according to the stacktrace, because if the wrapper or the
> context were null, it should have printed a different line number).
My experience with the Sun/Oracle compiler is that lines 288 and 289
will never be indicated in a stack trace: the line number of the start
of the statement is considered the line number for the entire statement.
> Unfortunately, I don't see this NPE anymore so I can't use a
> modified Tomcat to debug it.
Problem solved?
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAk4WfskACgkQ9CaO5/Lv0PC/2ACgmb7DqC4NjPO4d+jfyXaC2NlT
qOYAnjtdGop5mScGfTN1cbDItRMjLmNF
=Pv/3
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by eurotrans-Verlag <ve...@t-online.de>.
Hi Christopher,
> -----Original Message-----
> From: Christopher Schultz [mailto:chris@christopherschultz.net]
> Sent: Thursday, July 07, 2011 9:13 PM
>
> Looks like it. I would be very interested to know which of those
> objects
> is null: the container, the logger, the wrapper, or the context.
>
> - -chris
I thought the same (I suppose only container or the logger can be null, according to the stacktrace, because if the wrapper or the context were null, it should have printed a different line number). Unfortunately, I don't see this NPE anymore so I can't use a modified Tomcat to debug it.
Regards,
Konstantin Preißer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Konstantin Kolinko <kn...@gmail.com>.
2011/7/8 Christopher Schultz <ch...@christopherschultz.net>:
> On 7/7/2011 5:45 PM, eurotrans-Verlag wrote:
>> The logs on redeploy were this:
>>
>> 07.07.2011 00:24:09 org.apache.catalina.startup.HostConfig
>> checkResources INFO: Undeploying context []
>
> Uhh... that can't be good. Why does the context have no name?
>
It is the ROOT context, as you noted. Its contextPath is empty and
name just reflect that.
http://tomcat.apache.org/tomcat-7.0-doc/config/context.html#Naming
>> INFO: Deploying web application archive ROOT.war
>
> Is [] the name Tomcat sometimes gives the root context? I've actually
> never used a root context, so I don't know but I would have expected it
> to call the context [/] instead of [].
>
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by eurotrans-Verlag <ve...@t-online.de>.
> Maybe I can reproduce the
> NPE if I make a servlet that takes a long time to finish the request,
> to see what was the original exception that has been suppressed by the
> NPE.
OK, I was able to reproduce a NPE in TC 7.0.16 with a Servlet that calls "Thread.sleep(20000)", then make a request to that servlet and immediately redeploy that webapp. However, this time the NPE was not in StandardWrapperValve.invoke(), but in StandardContextValve.invoke():
08.07.2011 00:26:40 org.apache.catalina.connector.CoyoteAdapter service
SCHWERWIEGEND: An exception or error occurred in the container during the request processing
java.lang.NullPointerException
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:462)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:563)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:403)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:301)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:162)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:140)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:309)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
The lines around 172 in StandardContextValve are these:
166 // If the request was async at the start and an error occurred then
167 // the async error handling will kick-in and that will fire the
168 // request destroyed event *after* the error handling has taken
169 // place
170 if (!(request.isAsync() || (asyncAtStart && request.getAttribute(
171 RequestDispatcher.ERROR_EXCEPTION) != null))) {
172 context.fireRequestDestroyEvent(request);
173 }
The problem here is that "context" is null (I debugged TC in Eclipse). However, this time it seems that it is not another Exception that has been suppressed by a NPE.
I checked that the NPE in StandardContextValve.invoke() also occurs in Tomcat 7.0.18.
Unfortunately, I was not able to reproduce the NPE in StandardWrapperValve.invoke().
Regards,
Konstantin Preißer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Konstantin,
On 7/7/2011 5:45 PM, eurotrans-Verlag wrote:
> The logs on redeploy were this:
>
> 07.07.2011 00:24:09 org.apache.catalina.startup.HostConfig
> checkResources INFO: Undeploying context []
Uhh... that can't be good. Why does the context have no name?
> INFO: Deploying web application archive ROOT.war
Is [] the name Tomcat sometimes gives the root context? I've actually
never used a root context, so I don't know but I would have expected it
to call the context [/] instead of [].
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAk4Wf2IACgkQ9CaO5/Lv0PBe8QCfepgWQyMhBvWEzZyt8pNrBkHq
k10An35gSSNjXMZub8HiX4dLAts2JWE5
=Y/q+
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by eurotrans-Verlag <ve...@t-online.de>.
Hi Pid,
> -----Original Message-----
> From: Pid [mailto:pid@pidster.com]
> Sent: Thursday, July 07, 2011 10:24 PM
>
> Are you using parallel deployment or are you replacing the existing
> application when it's redeployed.
>
> Maybe the old context is the one throwing the error.
>
>
> p
I don't use parallel deployment.
To redeploy a webapp, I just replace the old war file with a new one and wait for Tomcat to redeploy it.
The logs on redeploy were this:
07.07.2011 00:24:09 org.apache.catalina.startup.HostConfig checkResources
INFO: Undeploying context []
07.07.2011 00:24:09 org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 1 instance(s) to be deallocated
07.07.2011 00:24:10 org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 1 instance(s) to be deallocated
07.07.2011 00:24:11 org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 1 instance(s) to be deallocated
07.07.2011 00:24:12 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SCHWERWIEGEND: The web application [] is still processing a request that has yet to finish. This is very likely to create a memory leak. You can control the time allowed for requests to finish by using the unloadDelay attribute of the standard Context implementation.
07.07.2011 00:24:12 org.apache.catalina.startup.ExpandWar deleteDir
SCHWERWIEGEND: [D:\tomcat7\work\Catalina\bildergalerie.pleier-it.de\_] could not be completely deleted. The presence of the remaining files may cause problems
07.07.2011 00:24:12 org.apache.catalina.startup.ExpandWar delete
SCHWERWIEGEND: [D:\tomcat7\work\Catalina\bildergalerie.pleier-it.de\_] could not be completely deleted. The presence of the remaining files may cause problems
07.07.2011 00:24:12 org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive ROOT.war
07.07.2011 00:24:17 org.apache.catalina.connector.CoyoteAdapter service
SCHWERWIEGEND: An exception or error occurred in the container during the request processing
java.lang.NullPointerException
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:287)
...
("SCHWERWIEGEND" should read like "SEVERE")
You're right, it could have something to do with the old context since it was still waiting for a request to finish. Maybe I can reproduce the NPE if I make a servlet that takes a long time to finish the request, to see what was the original exception that has been suppressed by the NPE.
Regards,
Konstantin Preißer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Pid <pi...@pidster.com>.
On 07/07/2011 20:59, eurotrans-Verlag wrote:
> Hi Christopher,
>
>> -----Original Message-----
>> From: Christopher Schultz [mailto:chris@christopherschultz.net]
>> Sent: Thursday, July 07, 2011 9:13 PM
>>
>> Looks like it. I would be very interested to know which of those
>> objects
>> is null: the container, the logger, the wrapper, or the context.
>>
>> - -chris
>
> I thought the same (I suppose only container or the logger can be null, according to the stacktrace, because if the wrapper or the context were null, it should have printed a different line number). Unfortunately, I don't see this NPE anymore so I can't use a modified Tomcat to debug it.
Are you using parallel deployment or are you replacing the existing
application when it's redeployed.
Maybe the old context is the one throwing the error.
p
Re: NPE at StandardWrapperValve.invoke() in Tomcat 7.0.16
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Konstantin,
On 7/6/2011 8:31 PM, eurotrans-Verlag wrote:
> I’m using Tomcat 7.0.16 on a system with Java 1.6.0_26 on Windows
> Serer 2008 and wondered about a strange NPE I got shortly after
> deploying a webapp to Tomcat:
>
> SCHWERWIEGEND: An exception or error occurred in the container during
> the request processing java.lang.NullPointerException at
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja
>
>
va:287)
>
> [...]
>
>> From looking at Tomcat 7.0.16's source, I can see that line 287 in
> StandardWrapperValve is inside a catch block:
>
> 285 } catch (Throwable e) { 286
> ExceptionUtils.handleThrowable(e); 287
> container.getLogger().error(sm.getString( 288
> "standardWrapper.serviceException", wrapper.getName(), 289
> context.getName()), e); 290 throwable = e; 291
> exception(request, response, e); 292 }
>
> So does that mean that another Exception/Error occurred, but was
> suppressed by that NPE and therefore couldn't be logged?
Looks like it. I would be very interested to know which of those objects
is null: the container, the logger, the wrapper, or the context.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAk4WBTwACgkQ9CaO5/Lv0PDjCQCghs2HebGAdzzsoeqT0dh+5I/E
PhgAn3SC4m1b8557I+YeS1r14IpcnrW1
=UIKh
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org