me0wster / javamelody

Automatically exported from code.google.com/p/javamelody
0 stars 0 forks source link

NullPointerException in MonitoringFilter.doFilter() (javamelody 1.39.0) #262

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
What steps will reproduce the problem?
1. Happens randomly shortly after the app server starts.
2.
3.

What is the expected output? What do you see instead?
There should never be NPE in MonitoringFilter.  However on some occasions 
shortly after starting our web application, lots of incoming requests fail due 
to NPE in MonitoringFilter (stack trace below.)  The issue then resolves itself 
and is not noticed again.

What version of the product are you using? On what application server, JDK,
operating system?
Application server:
Jetty 8.1.3.v20120416

JDK:
java version "1.6.0_24"
OpenJDK Runtime Environment (IcedTea6 1.11.4) (6b24-1.11.4-1ubuntu0.12.04.1)
OpenJDK 64-Bit Server VM (build 20.0-b12, mixed mode)

OS (on Amazon EC2 instance):
Linux ip-x-x-x-x 3.2.0-31-virtual #50-Ubuntu SMP Fri Sep 7 16:36:36 UTC 2012 
x86_64 x86_64 x86_64 GNU/Linux

Please provide any additional information below.
The NPE is thrown at line 258 "httpCounter.unbindContext();".  It appears to me 
that this private field httpCounter should be declared volatile.  It is 
assigned a value in the filter init() method, then accessed from doFilter (and 
other places.)  Many different threads will call doFilter() -- declaring the 
httpCounter field as volatile ensures they will all see it in its more current 
state.  Stack trace below (javamelody 1.39.0):

java.lang.NullPointerException: null
        at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:258) ~[cdb.jar:1.0.3-SNAPSHOT]
        at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:175) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:311) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:116) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:101) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:182) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:173) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338) ~[cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:484) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:233) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) [cdb.jar:1.0.3-SNAPSHOT]
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [cdb.jar:1.0.3-SNAPSHOT]
<more omitted>

Thank you.

Original issue reported on code.google.com by colin...@gmail.com on 24 Oct 2012 at 6:07

GoogleCodeExporter commented 9 years ago
httpCounter is not supposed to be null when doFilter is called. And doFilter is 
not supposed to be called before init has initialized httpCounter. And in 
general, the destroy method of the same class "is only called once all threads 
within the filter's doFilter method have exited".

But, the destroy method sets httpCounter to null.
And it may also happen after a timeout in the http requests, that Jetty calls 
the destroy method before the end of all doFilter calls, when the webapp is 
undeployed or redeployed.
And so, there is the NPE when the doFilter calls finally end.
The webapp was undeployed anyway.

I have made a change in trunk (revision 3095) which should fix most if not all 
of those exceptions. It is ready for the next release (1.42).

I have made a new build from the current trunk and it is available at:
http://javamelody.googlecode.com/files/javamelody-20121027.jar

Original comment by evernat@free.fr on 27 Oct 2012 at 10:15

GoogleCodeExporter commented 9 years ago
Looking over my logs again, you are correct.  These NPE were thrown as the 
application was shutting down, not during startup.  So my original description 
is incorrect.

But I still believe for thread safety the httpCounter field should be declared 
volatile.  See the "Pattern #2: one-time safe publication" section at this link 
for an explanation:
http://www.ibm.com/developerworks/java/library/j-jtp06197/index.html

BTW Javamelody has been invaluable on my current project.  Thank you for all 
the hard work.

Original comment by colin...@gmail.com on 30 Oct 2012 at 4:03