Double-entry on pointcut?
cuplan Jul 2, 2003 11:25 AMI hope this is the correct forum to be posting this to. FCCI's system architect has scrounged up a little work time for me to start our development of our AOP system monitoring ideas. I won't bore people with the details at this juncture, but suffice it to say that one of the pointcuts we need to have is across a common entry point for our Servlets. Now, I've been quite able to get interceptors to pointcut on a base class still under JBoss classloader control like javax.servlet.http.HttpServlet. What's interesting, though, is thatif we use a basic Interceptor like the TracingInterceptor from the AOP demos, the call to the service() method of HttpServlet shows two entrances to the method on the same thread. Curious about this, I dumped the stacktraces and got the following:
10:25:50,960 INFO [STDOUT] Entering method: service on thread PoolThread-4
10:25:50,960 INFO [STDOUT] Stacktrace:
10:25:50,960 ERROR [STDERR] java.lang.Exception: Stack trace
10:25:50,960 ERROR [STDERR] at java.lang.Thread.dumpStack(Thread.java:1071)
10:25:50,960 ERROR [STDERR] at TracingInterceptor.invoke(TracingInterceptor.java:51)
10:25:50,960 ERROR [STDERR] at org.jboss.aop.Invocation.invokeNext(Invocation.java:93)
10:25:50,960 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeMethod(ClassAdvisor.java:411)
10:25:50,960 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeMethod(ClassAdvisor.java:386)
10:25:50,960 ERROR [STDERR] at javax.servlet.http.HttpServlet._added_m$0(HttpServlet.java)
10:25:50,960 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java)
10:25:50,970 ERROR [STDERR] at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:360)
10:25:50,970 ERROR [STDERR] at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:294)
10:25:50,970 ERROR [STDERR] at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:558)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.HttpContext.handle(HttpContext.java:1714)
10:25:50,970 ERROR [STDERR] at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:507)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.HttpContext.handle(HttpContext.java:1664)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.HttpServer.service(HttpServer.java:861)
10:25:50,970 ERROR [STDERR] at org.jboss.jetty.Jetty.service(Jetty.java:497)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.HttpConnection.service(HttpConnection.java:773)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:935)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.HttpConnection.handle(HttpConnection.java:790)
10:25:50,970 ERROR [STDERR] at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:201)
10:25:50,970 ERROR [STDERR] at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:289)
10:25:50,970 ERROR [STDERR] at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:454)
10:25:50,970 INFO [STDOUT] Entering method: service on thread PoolThread-4
10:25:50,970 INFO [STDOUT] Stacktrace:
10:25:50,970 ERROR [STDERR] java.lang.Exception: Stack trace
10:25:50,970 ERROR [STDERR] at java.lang.Thread.dumpStack(Thread.java:1071)
10:25:50,970 ERROR [STDERR] at TracingInterceptor.invoke(TracingInterceptor.java:51)
10:25:50,970 ERROR [STDERR] at org.jboss.aop.Invocation.invokeNext(Invocation.java:93)
10:25:50,970 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeMethod(ClassAdvisor.java:411)
10:25:50,970 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeMethod(ClassAdvisor.java:386)
10:25:50,970 ERROR [STDERR] at javax.servlet.http.HttpServlet._added_m$0(HttpServlet.java)
10:25:50,970 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java)
10:25:50,970 ERROR [STDERR] at javax.servlet.http.HttpServlet.javax$servlet$http$HttpServlet$service$WithoutAdvisement(HttpServlet.java:853)
10:25:50,980 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
10:25:50,980 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
10:25:50,980 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
10:25:50,980 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
10:25:50,980 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeWithoutAdvisement(ClassAdvisor.java:349)
10:25:50,980 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invoke(ClassAdvisor.java:563)
10:25:50,980 ERROR [STDERR] at org.jboss.aop.Invocation.invokeNext(Invocation.java:93)
10:25:50,980 ERROR [STDERR] at TracingInterceptor.invoke(TracingInterceptor.java:52)
10:25:50,980 ERROR [STDERR] at org.jboss.aop.Invocation.invokeNext(Invocation.java:93)
10:25:50,980 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeMethod(ClassAdvisor.java:411)
10:25:50,980 ERROR [STDERR] at org.jboss.aop.ClassAdvisor.invokeMethod(ClassAdvisor.java:386)
10:25:50,980 ERROR [STDERR] at javax.servlet.http.HttpServlet._added_m$0(HttpServlet.java)
10:25:50,980 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java)
10:25:50,980 ERROR [STDERR] at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:360)
10:25:50,980 ERROR [STDERR] at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:294)
10:25:50,980 ERROR [STDERR] at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:558)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.HttpContext.handle(HttpContext.java:1714)
10:25:50,980 ERROR [STDERR] at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:507)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.HttpContext.handle(HttpContext.java:1664)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.HttpServer.service(HttpServer.java:861)
10:25:50,980 ERROR [STDERR] at org.jboss.jetty.Jetty.service(Jetty.java:497)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.HttpConnection.service(HttpConnection.java:773)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:935)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.HttpConnection.handle(HttpConnection.java:790)
10:25:50,980 ERROR [STDERR] at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:201)
10:25:50,980 ERROR [STDERR] at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:289)
10:25:50,980 ERROR [STDERR] at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:454)
As you can see, the two different entries into this method have some minor differences in their stacks. This is the only method that has a double entry on it...all the methods that appear to be "below" it on a normally expected thread of execution have one entry and one exit...nice and neat.
Any reason why this might be happening and how I can combat it? I'm sure it's just something I've overlooked on my side, but I'm a touch stumped.