Can you do one other thing - disable inspektr altogether and do the logout with memcached ticket registry. See if there are any exceptions.
Dmitriy. Sent from my iPad On Apr 18, 2012, at 4:59 PM, Bryan Wooten <[email protected]> wrote: > Thanks for the reply Marv, > > I am hoping to avoid downloading the inspektr source and stepping through all > the code. I pretty sure it is some minor config error but I am not sure where > to look. My ticketRegistry.xml is right off the wiki for using memcahed. > > I have this setting in my log4j.xml file, but it doesn't seem add any further > data. > > <logger > name="com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager"> > > <level value="DEBUG" /> > <appender-ref ref="cas" /> > </logger> > > When I login I see this: > #|2012-04-18T14:45:26.091-0600|INFO|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_ThreadID=28;_ThreadName=Thread-1;|2012-04-18 > 14:45:26,091 INFO [org.jas > ig.cas.authentication.AuthenticationManagerImpl] - <Principal found: u0519980> > |#] > > [#|2012-04-18T14:45:26.132-0600|INFO|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_ThreadID=28;_ThreadName=Thread-1;|Audit > trail record BEGIN > ============================================================= > WHO: [username: u0519980] > WHAT: supplied credentials: [username: u0519980] > ACTION: AUTHENTICATION_SUCCESS > APPLICATION: CAS > WHEN: Wed Apr 18 14:45:26 MDT 2012 > CLIENT IP ADDRESS: 128.110.140.67 > SERVER IP ADDRESS: 155.97.166.161 > ============================================================= > > |#] > > [#|2012-04-18T14:45:26.577-0600|INFO|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_ThreadID=28;_ThreadName=Thread-1;|Audit > trail record BEGIN > ============================================================= > WHO: [username: u0519980] > WHAT: TGT-1-tBUkUHk2fZ7iKde3NBnsh0BXQrh0jdfbkdk5QSycTTqqWcbBPS-testcas2 > ACTION: TICKET_GRANTING_TICKET_CREATED > APPLICATION: CAS > WHEN: Wed Apr 18 14:45:26 MDT 2012 > CLIENT IP ADDRESS: 128.110.140.67 > SERVER IP ADDRESS: 155.97.166.161 > ============================================================= > > > Here is the full stack trace when I logout: > > [#|2012-04-18T14:45:48.882-0600|INFO|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_ThreadID=28;_ThreadName=Thread-1;|2012-04-18 > 14:45:48,882 INFO [org.spr > ingframework.web.servlet.handler.SimpleUrlHandlerMapping] - <Mapped URL path > [/authorizationFailure.html] onto handler 'passThroughController'> > |#] > > [#|2012-04-18T14:45:48.904-0600|INFO|glassfish3.0.1|org.hibernate.validator.engine.resolver.DefaultTraversableResolver|_ThreadID=28;_ThreadName=Thread-1;|Instantiated > an instance of org.hi > bernate.validator.engine.resolver.JPATraversableResolver.|#] > > [#|2012-04-18T14:45:48.908-0600|INFO|glassfish3.0.1|org.hibernate.validator.engine.resolver.DefaultTraversableResolver|_ThreadID=28;_ThreadName=Thread-1;|Instantiated > an instance of org.hi > bernate.validator.engine.resolver.JPATraversableResolver.|#] > > [#|2012-04-18T14:45:48.920-0600|INFO|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_ThreadID=28;_ThreadName=Thread-1;|2012-04-18 > 14:45:48,920 INFO [org.spr > ingframework.web.servlet.DispatcherServlet] - <FrameworkServlet 'cas': > initialization completed in 193 ms> > |#] > > [#|2012-04-18T14:45:51.023-0600|WARNING|glassfish3.0.1|javax.enterprise.system.container.web.com.sun.enterprise.web|_ThreadID=28;_ThreadName=http-thread-pool-9022-(2);|StandardWrapperValve > [cas]: PWC1406: Servlet.service() for servlet cas threw exception > java.lang.NullPointerException > at > com.github.inspektr.audit.AuditTrailManagementAspect.executeAuditCode(AuditTrailManagementAspect.java:147) > at > com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:139) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) > at > org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) > at > org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80) > at > org.perf4j.aop.AbstractTimingAspect$1.proceed(AbstractTimingAspect.java:47) > at > org.perf4j.aop.AgnosticTimingAspect.runProfiledMethod(AgnosticTimingAspect.java:53) > at > org.perf4j.aop.AbstractTimingAspect.doPerfLogging(AbstractTimingAspect.java:45) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) > at > org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) > at > org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) > at $Proxy134.destroyTicketGrantingTicket(Unknown Source) > at > org.jasig.cas.web.LogoutController.handleRequestInternal(LogoutController.java:64) > at > org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153) > at > org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48) > at > org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:790) > at > org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:719) > at > org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:644) > at > org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:549) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:734) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) > at > org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody2(SafeDispatcherServlet.java:115) > at > org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody3$advice(SafeDispatcherServlet.java:44) > at > org.jasig.cas.web.init.SafeDispatcherServlet.service(SafeDispatcherServlet.java:1) > at > org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1523) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) > at > com.github.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:63) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) > at > org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) > at > org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237) > at > org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) > at > org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:277) > at > org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:188) > at > org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:641) > at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97) > at > com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85) > at > org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185) > at > org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:325) > at > org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226) > at > com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:165) > at > com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791) > at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693) > at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954) > at > com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170) > at > com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135) > at > com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102) > at > com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88) > at > com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76) > at > com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53) > at > com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57) > at com.sun.grizzly.ContextTask.run(ContextTask.java:69) > at > com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330) > at > com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309) > at java.lang.Thread.run(Thread.java:662) > |#] > > [#|2012-04-18T14:45:51.023-0600|WARNING|glassfish3.0.1|javax.enterprise.system.container.web.com.sun.enterprise.web|_ThreadID=28;_ThreadName=Thread-1;|StandardWrapperValve[cas]: > PWC1406: S > ervlet.service() for servlet cas threw exception > java.lang.NullPointerException > at > com.github.inspektr.audit.AuditTrailManagementAspect.executeAuditCode(AuditTrailManagementAspect.java:147) > at > com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:139) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) > at > org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) > at > org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80) > at > org.perf4j.aop.AbstractTimingAspect$1.proceed(AbstractTimingAspect.java:47) > at > org.perf4j.aop.AgnosticTimingAspect.runProfiledMethod(AgnosticTimingAspect.java:53) > at > org.perf4j.aop.AbstractTimingAspect.doPerfLogging(AbstractTimingAspect.java:45) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) > at > org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) > at > org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) > at > org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) > at $Proxy134.destroyTicketGrantingTicket(Unknown Source) > at > org.jasig.cas.web.LogoutController.handleRequestInternal(LogoutController.java:64) > at > org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153) > at > org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48) > at > org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:790) > at > org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:719) > at > org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:644) > at > org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:549) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:734) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) > at > org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody2(SafeDispatcherServlet.java:115) > at > org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody3$advice(SafeDispatcherServlet.java:44) > at > org.jasig.cas.web.init.SafeDispatcherServlet.service(SafeDispatcherServlet.java:1) > at > org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1523) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) > at > com.github.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:63) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) > at > org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) > at > org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237) > at > org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) > at > org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:277) > at > org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:188) > at > org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:641) > at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97) > at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97) > at > com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85) > at > org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185) > at > org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:325) > at > org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226) > at > com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:165) > at > com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791) > at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693) > at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954) > at > com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170) > at > com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135) > at > com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102) > at > com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88) > at > com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76) > at > com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53) > at > com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57) > at com.sun.grizzly.ContextTask.run(ContextTask.java:69) > at > com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330) > at > com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309) > at java.lang.Thread.run(Thread.java:662) > |#] > -----Original Message----- > From: Marvin Addison [mailto:[email protected]] > Sent: Wednesday, April 18, 2012 2:23 PM > To: [email protected] > Subject: Re: [cas-user] Memcached Ticket Registry - Unresolved > >> Any ideas why switching from JPA ticket registry to memcached ticket >> registry would affect auditing? I upped inspektr logging to debug but don't >> see any addition log information. > > The exception you cited below offers only a hint, but it's better than > nothing. > >> [#|2012-04-17T13:15:41.901-0600|WARNING|glassfish3.0.1|javax.enterprise.system.container.web.com.sun.enterprise.web|_ThreadID=30;_ThreadName=http-thread-pool-9022-(3);|StandardWrapperValve >> [cas]: PWC1406: Servlet.service() for servlet cas threw exception >> java.lang.NullPointerException >> at >> com.github.inspektr.audit.AuditTrailManagementAspect.executeAuditCode(AuditTrailManagementAspect.java:147) >> at >> com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:139) >> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >> at >> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) >> at >> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >> at java.lang.reflect.Method.invoke(Method.java:597) > > This can happen if both the try and catch blocks in handleAuditTrail both > throw exceptions, in which case the finally block that logs the audit entry > has a null resolver [1]. > > While the Inspektr docs say the resolver is supposed to handle all exceptions > internally, I've seen this error occur when I've got try {...} catch > (Exception e){...} in my resolvers. I haven't spent the time to track down > specific causes because it rarely happens, but your case fits the general > outline. > > A quick review of source for Inspektr 1.0.5.GA, which is the version that > ships with 3.4.11, indicates this could be the problem since the NPE is > thrown when an attempt is made to iterate over a collection that would be > null in the scenario I described. (I'm matching up line numbers from your > stack trace.) Unfortunately the only way for you to get more information is > to add more logging to Inspektr and recompile. I really think Inspektr > should either provide more protection or information for cases like these. I > opened an issue [2] along those lines long ago but never followed through on > it. Maybe it's time to pursue? > > M > > [1] > https://github.com/dima767/inspektr/blob/c1677b560687ff1954fe106c7a664780d86513eb/inspektr-audit/src/main/java/com/github/inspektr/audit/AuditTrailManagementAspect.java > > [2] https://github.com/dima767/inspektr/issues/10 > > -- > You are currently subscribed to [email protected] as: > [email protected] > To unsubscribe, change settings or access archives, see > http://www.ja-sig.org/wiki/display/JSG/cas-user > -- You are currently subscribed to [email protected] as: [email protected] To unsubscribe, change settings or access archives, see http://www.ja-sig.org/wiki/display/JSG/cas-user
