CAS 4.1.0 Snapshot - Single Sign Out - Back Channel Exception

37 views
Skip to first unread message

Vit Rozkovec

unread,
Nov 30, 2014, 1:19:37 PM11/30/14
to jasig-c...@googlegroups.com
Hi,
I am trying to get SLO working, however without success. I have came across this exception that happens after the first POST to the service that we need user to log out from.

It happens in the following sequence:

  1. CAS: Start server
  2. BROWSER: login into the services (in my test I am trying with 3 services)
  3. BROWSER: logout from one service
  4. CAS: POST to first service - ok
    • SimpleHttpClient's ExecutorService status: shutdown - false, terminated - false, pool size - 0
  5. CAS: POST to second service - exception
    • SimpleHttpClient's ExecutorService status: shutdown - true, terminated - false, pool size - 1
  6. CAS: POST to third service - exception - same situation as above (5)

My guess is that ExecutorService gets closed somewhere and when SimpleHttpClient wants to use it, exception is thrown. I do not know where, though, as I added

LOGGER.debug("Executor service shutdown");

to the destroy() method of the SimpleHttpClient and this debug message does not appear in the log.


Do you have any ideas what may be wrong?

Thank you.



Regards

Vit



Full log with stacktrace (I have added some debug logs to see what is happening, the log starts with first successful POST, enabled TRACE log for package org.jasig.cas.util):

2014-11-29 01:30:39,202 DEBUG [org.jasig.cas.logout.
SamlCompliantLogoutMessageCreator] - <Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-1-jbep59j1kovlc1WYceGiaDGtcIazCxLllwf" Version="2.0" IssueInstant="2014-11-29T01:30:39Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-1-0Zq3jhNatF4TbGQEqesx-maneki.berries.name</samlp:SessionIndex></samlp:LogoutRequest>]>
2014-11-29 01:30:39,202 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - <Sending logout request for: [http://festinalentepress.cz/callback]>
2014-11-29 01:30:39,202 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - <Original url: [http://festinalentepress.cz/callback]>
2014-11-29 01:30:39,203 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Entering method [sendMessageToEndPoint] with arguments [[org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@64d3257c]]>
2014-11-29 01:30:39,203 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Message URL: [http://festinalentepress.cz/callback]>
2014-11-29 01:30:39,219 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service shutdown: [false]>
2014-11-29 01:30:39,219 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service terminated: [false]>
2014-11-29 01:30:39,219 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service pool size: [0]>
2014-11-29 01:30:39,225 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Message asynchronous: [true]>
2014-11-29 01:30:39,227 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] - <Connection manager is shutting down>
2014-11-29 01:30:39,228 DEBUG [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] - <Connection manager shut down>
2014-11-29 01:30:39,228 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Leaving method [sendMessageToEndPoint] with return value [true].>
2014-11-29 01:30:39,229 TRACE [org.jasig.cas.util.DefaultUniqueTicketIdGenerator] - <Entering method [getNewTicketId] with arguments [[LR]]>
2014-11-29 01:30:39,229 TRACE [org.jasig.cas.util.DefaultLongNumericGenerator] - <Entering method [getNextNumberAsString] with arguments []>
2014-11-29 01:30:39,229 TRACE [org.jasig.cas.util.DefaultLongNumericGenerator] - <Leaving method [getNextNumberAsString] with return value [2].>
2014-11-29 01:30:39,229 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Entering method [getMaxLength] with arguments []>
2014-11-29 01:30:39,229 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Leaving method [getMaxLength] with return value [35].>
2014-11-29 01:30:39,230 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Entering method [getNewString] with arguments []>
2014-11-29 01:30:39,230 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Entering method [getNewStringAsBytes] with arguments []>
2014-11-29 01:30:39,230 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Leaving method [getNewStringAsBytes] with return value [[B@609db0e].>
2014-11-29 01:30:39,230 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Leaving method [getNewString] with return value [uRPo4Oi4bTgFfXpb9nueFDhIjoFO5CbRsw3].>
2014-11-29 01:30:39,230 TRACE [org.jasig.cas.util.DefaultUniqueTicketIdGenerator] - <Leaving method [getNewTicketId] with return value [LR-2-uRPo4Oi4bTgFfXpb9nueFDhIjoFO5CbRsw3].>
2014-11-29 01:30:39,232 TRACE [org.jasig.cas.util.ISOStandardDateFormat] - <Entering method [getCurrentDateAndTime] with arguments []>
2014-11-29 01:30:39,233 TRACE [org.jasig.cas.util.ISOStandardDateFormat] - <Leaving method [getCurrentDateAndTime] with return value [2014-11-29T01:30:39Z].>
2014-11-29 01:30:39,233 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - <Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-2-uRPo4Oi4bTgFfXpb9nueFDhIjoFO5CbRsw3" Version="2.0" IssueInstant="2014-11-29T01:30:39Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-2-OFguJeG0kEcfwyRevs1A-maneki.berries.name</samlp:SessionIndex></samlp:LogoutRequest>]>
2014-11-29 01:30:39,233 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - <Sending logout request for: [http://nikkarin.cz/callback]>
2014-11-29 01:30:39,233 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - <Original url: [http://nikkarin.cz/callback]>
2014-11-29 01:30:39,233 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Entering method [sendMessageToEndPoint] with arguments [[org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@29d4c6f3]]>
2014-11-29 01:30:39,234 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Message URL: [http://nikkarin.cz/callback]>
2014-11-29 01:30:39,235 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service shutdown: [true]>
2014-11-29 01:30:39,235 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service terminated: [false]>
2014-11-29 01:30:39,235 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service pool size: [1]>
2014-11-29 01:30:39,236 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Task http://nikkarin.cz/callback rejected from java.util.concurrent.ThreadPoolExecutor@4c8459d9[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]>
java.util.concurrent.RejectedExecutionException: Task http://nikkarin.cz/callback rejected from java.util.concurrent.ThreadPoolExecutor@4c8459d9[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]
    at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
    at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
    at org.apache.http.impl.client.FutureRequestExecutionService.execute(FutureRequestExecutionService.java:122)
    at org.apache.http.impl.client.FutureRequestExecutionService.execute(FutureRequestExecutionService.java:89)
    at org.jasig.cas.util.SimpleHttpClient.sendMessageToEndPoint_aroundBody0(SimpleHttpClient.java:362)
    at org.jasig.cas.util.SimpleHttpClient.sendMessageToEndPoint_aroundBody1$advice(SimpleHttpClient.java:62)
    at org.jasig.cas.util.SimpleHttpClient.sendMessageToEndPoint(SimpleHttpClient.java:1)
    at org.jasig.cas.logout.LogoutManagerImpl.performBackChannelLogout(LogoutManagerImpl.java:213)
    at org.jasig.cas.logout.LogoutManagerImpl.handleLogoutForSloService(LogoutManagerImpl.java:181)
    at org.jasig.cas.logout.LogoutManagerImpl.performLogout_aroundBody0(LogoutManagerImpl.java:139)
    at org.jasig.cas.logout.LogoutManagerImpl.performLogout_aroundBody1$advice(LogoutManagerImpl.java:62)
    at org.jasig.cas.logout.LogoutManagerImpl.performLogout(LogoutManagerImpl.java:1)
    at org.jasig.cas.CentralAuthenticationServiceImpl.destroyTicketGrantingTicket_aroundBody0(CentralAuthenticationServiceImpl.java:214)
    at org.jasig.cas.CentralAuthenticationServiceImpl.destroyTicketGrantingTicket_aroundBody1$advice(CentralAuthenticationServiceImpl.java:62)
    at org.jasig.cas.CentralAuthenticationServiceImpl.destroyTicketGrantingTicket(CentralAuthenticationServiceImpl.java:1)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    at com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:126)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:68)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    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:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:68)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy29.destroyTicketGrantingTicket(Unknown Source)
    at org.jasig.cas.web.flow.TerminateSessionAction.terminate(TerminateSessionAction.java:86)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.expression.spel.support.ReflectiveMethodExecutor.execute(ReflectiveMethodExecutor.java:72)
    at org.springframework.expression.spel.ast.MethodReference.getValueInternal(MethodReference.java:102)
    at org.springframework.expression.spel.ast.MethodReference.access$000(MethodReference.java:49)
    at org.springframework.expression.spel.ast.MethodReference$MethodValueRef.getValue(MethodReference.java:347)
    at org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:87)
    at org.springframework.expression.spel.ast.SpelNodeImpl.getTypedValue(SpelNodeImpl.java:126)
    at org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:296)
    at org.springframework.binding.expression.spel.SpringELExpression.getValue(SpringELExpression.java:84)
    at org.springframework.webflow.action.EvaluateAction.doExecute(EvaluateAction.java:75)
    at org.springframework.webflow.action.AbstractAction.execute(AbstractAction.java:188)
    at org.springframework.webflow.execution.AnnotatedAction.execute(AnnotatedAction.java:145)
    at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:51)
    at org.springframework.webflow.engine.ActionState.doEnter(ActionState.java:101)
    at org.springframework.webflow.engine.State.enter(State.java:194)
    at org.springframework.webflow.engine.Flow.start(Flow.java:527)
    at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:368)
    at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:223)
    at org.springframework.webflow.executor.FlowExecutorImpl.launchExecution(FlowExecutorImpl.java:140)
    at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:238)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:943)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:877)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:857)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:735)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:698)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1506)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1494)
    at com.github.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:63)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1486)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:503)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:138)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:564)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:213)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1094)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:432)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:175)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1028)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:136)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:258)
    at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
    at org.eclipse.jetty.server.Server.handle(Server.java:445)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:267)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:224)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
    at java.lang.Thread.run(Thread.java:745)
2014-11-29 01:30:39,242 DEBUG [org.apache.http.client.protocol.RequestAddCookies] - <CookieSpec selected: best-match>
2014-11-29 01:30:39,242 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Leaving method [sendMessageToEndPoint] with return value [false].>
2014-11-29 01:30:39,242 WARN [org.jasig.cas.logout.LogoutManagerImpl] - <Logout message not sent to [http://nikkarin.cz/callback]; Continuing processing...>
2014-11-29 01:30:39,244 TRACE [org.jasig.cas.util.DefaultUniqueTicketIdGenerator] - <Entering method [getNewTicketId] with arguments [[LR]]>
2014-11-29 01:30:39,244 TRACE [org.jasig.cas.util.DefaultLongNumericGenerator] - <Entering method [getNextNumberAsString] with arguments []>
2014-11-29 01:30:39,244 TRACE [org.jasig.cas.util.DefaultLongNumericGenerator] - <Leaving method [getNextNumberAsString] with return value [3].>
2014-11-29 01:30:39,244 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Entering method [getMaxLength] with arguments []>
2014-11-29 01:30:39,244 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Leaving method [getMaxLength] with return value [35].>
2014-11-29 01:30:39,245 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Entering method [getNewString] with arguments []>
2014-11-29 01:30:39,245 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Entering method [getNewStringAsBytes] with arguments []>
2014-11-29 01:30:39,245 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Leaving method [getNewStringAsBytes] with return value [[B@6e71a5fc].>
2014-11-29 01:30:39,245 TRACE [org.jasig.cas.util.DefaultRandomStringGenerator] - <Leaving method [getNewString] with return value [HmobUdTsxmroV0dCELWafpsa5eEbyR6OSdR].>
2014-11-29 01:30:39,245 TRACE [org.jasig.cas.util.DefaultUniqueTicketIdGenerator] - <Leaving method [getNewTicketId] with return value [LR-3-HmobUdTsxmroV0dCELWafpsa5eEbyR6OSdR].>
2014-11-29 01:30:39,246 TRACE [org.jasig.cas.util.ISOStandardDateFormat] - <Entering method [getCurrentDateAndTime] with arguments []>
2014-11-29 01:30:39,246 TRACE [org.jasig.cas.util.ISOStandardDateFormat] - <Leaving method [getCurrentDateAndTime] with return value [2014-11-29T01:30:39Z].>
2014-11-29 01:30:39,247 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - <Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-3-HmobUdTsxmroV0dCELWafpsa5eEbyR6OSdR" Version="2.0" IssueInstant="2014-11-29T01:30:39Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-3-aBc0lqhrKZaSbgvBbnGG-maneki.berries.name</samlp:SessionIndex></samlp:LogoutRequest>]>
2014-11-29 01:30:39,247 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - <Sending logout request for: [http://unitedkingdog.com/callback]>
2014-11-29 01:30:39,247 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - <Original url: [http://unitedkingdog.com/callback]>
2014-11-29 01:30:39,247 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Entering method [sendMessageToEndPoint] with arguments [[org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@76f6fcd2]]>
2014-11-29 01:30:39,247 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Message URL: [http://unitedkingdog.com/callback]>
2014-11-29 01:30:39,249 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service shutdown: [true]>
2014-11-29 01:30:39,249 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service terminated: [false]>
2014-11-29 01:30:39,249 DEBUG [org.jasig.cas.util.SimpleHttpClient] - <Executor service pool size: [1]>
2014-11-29 01:30:39,249 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Task http://unitedkingdog.com/callback rejected from java.util.concurrent.ThreadPoolExecutor@4c8459d9[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]>
java.util.concurrent.RejectedExecutionException: Task http://unitedkingdog.com/callback rejected from java.util.concurrent.ThreadPoolExecutor@4c8459d9[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]
    at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
    at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
    at org.apache.http.impl.client.FutureRequestExecutionService.execute(FutureRequestExecutionService.java:122)
    at org.apache.http.impl.client.FutureRequestExecutionService.execute(FutureRequestExecutionService.java:89)
    at org.jasig.cas.util.SimpleHttpClient.sendMessageToEndPoint_aroundBody0(SimpleHttpClient.java:362)
    at org.jasig.cas.util.SimpleHttpClient.sendMessageToEndPoint_aroundBody1$advice(SimpleHttpClient.java:62)
    at org.jasig.cas.util.SimpleHttpClient.sendMessageToEndPoint(SimpleHttpClient.java:1)
    at org.jasig.cas.logout.LogoutManagerImpl.performBackChannelLogout(LogoutManagerImpl.java:213)
    at org.jasig.cas.logout.LogoutManagerImpl.handleLogoutForSloService(LogoutManagerImpl.java:181)
    at org.jasig.cas.logout.LogoutManagerImpl.performLogout_aroundBody0(LogoutManagerImpl.java:139)
    at org.jasig.cas.logout.LogoutManagerImpl.performLogout_aroundBody1$advice(LogoutManagerImpl.java:62)
    at org.jasig.cas.logout.LogoutManagerImpl.performLogout(LogoutManagerImpl.java:1)
    at org.jasig.cas.CentralAuthenticationServiceImpl.destroyTicketGrantingTicket_aroundBody0(CentralAuthenticationServiceImpl.java:214)
    at org.jasig.cas.CentralAuthenticationServiceImpl.destroyTicketGrantingTicket_aroundBody1$advice(CentralAuthenticationServiceImpl.java:62)
    at org.jasig.cas.CentralAuthenticationServiceImpl.destroyTicketGrantingTicket(CentralAuthenticationServiceImpl.java:1)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    at com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:126)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:68)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    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:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:68)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy29.destroyTicketGrantingTicket(Unknown Source)
    at org.jasig.cas.web.flow.TerminateSessionAction.terminate(TerminateSessionAction.java:86)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.expression.spel.support.ReflectiveMethodExecutor.execute(ReflectiveMethodExecutor.java:72)
    at org.springframework.expression.spel.ast.MethodReference.getValueInternal(MethodReference.java:102)
    at org.springframework.expression.spel.ast.MethodReference.access$000(MethodReference.java:49)
    at org.springframework.expression.spel.ast.MethodReference$MethodValueRef.getValue(MethodReference.java:347)
    at org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:87)
    at org.springframework.expression.spel.ast.SpelNodeImpl.getTypedValue(SpelNodeImpl.java:126)
    at org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:296)
    at org.springframework.binding.expression.spel.SpringELExpression.getValue(SpringELExpression.java:84)
    at org.springframework.webflow.action.EvaluateAction.doExecute(EvaluateAction.java:75)
    at org.springframework.webflow.action.AbstractAction.execute(AbstractAction.java:188)
    at org.springframework.webflow.execution.AnnotatedAction.execute(AnnotatedAction.java:145)
    at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:51)
    at org.springframework.webflow.engine.ActionState.doEnter(ActionState.java:101)
    at org.springframework.webflow.engine.State.enter(State.java:194)
    at org.springframework.webflow.engine.Flow.start(Flow.java:527)
    at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:368)
    at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:223)
    at org.springframework.webflow.executor.FlowExecutorImpl.launchExecution(FlowExecutorImpl.java:140)
    at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:238)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:943)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:877)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:857)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:735)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:698)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1506)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1494)
    at com.github.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:63)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1486)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:503)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:138)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:564)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:213)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1094)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:432)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:175)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1028)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:136)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:258)
    at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
    at org.eclipse.jetty.server.Server.handle(Server.java:445)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:267)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:224)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
    at java.lang.Thread.run(Thread.java:745)
2014-11-29 01:30:39,255 TRACE [org.jasig.cas.util.SimpleHttpClient] - <Leaving method [sendMessageToEndPoint] with return value [false].>
2014-11-29 01:30:39,255 WARN [org.jasig.cas.logout.LogoutManagerImpl] - <Logout message not sent to [http://unitedkingdog.com/callback]; Continuing processing...>
2014-11-29 01:30:39,255 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Removing ticket [TGT-1-LvHancFEpKR3NcQF39qawbFA7zMo2e6xgcYuooAcHOR54KbTCP-maneki.berries.name] from registry>
2014-11-29 01:30:39,256 DEBUG [org.jasig.cas.audit.spi.TicketOrCredentialPrincipalResolver] - <Resolving argument [String] for audit>
2014-11-29 01:30:39,256 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Attempting to retrieve ticket [TGT-1-LvHancFEpKR3NcQF39qawbFA7zMo2e6xgcYuooAcHOR54KbTCP-maneki.berries.name]>
2014-11-29 01:30:39,256 DEBUG [org.jasig.cas.CentralAuthenticationServiceImpl] - <Ticket [TGT-1-LvHancFEpKR3NcQF39qawbFA7zMo2e6xgcYuooAcHOR54KbTCP-maneki.berries.name] by type [Ticket] cannot be found in the ticket registry.>
2014-11-29 01:30:39,256 DEBUG [org.jasig.cas.audit.spi.TicketOrCredentialPrincipalResolver] - <Could not locate ticket [TGT-1-LvHancFEpKR3NcQF39qawbFA7zMo2e6xgcYuooAcHOR54KbTCP-maneki.berries.name] in the registry>
2014-11-29 01:30:39,256 DEBUG [org.jasig.cas.audit.spi.TicketOrCredentialPrincipalResolver] - <Unable to determine the audit argument. Returning [audit:unknown]>
2014-11-29 01:30:39,257 INFO [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: TGT-1-LvHancFEpKR3NcQF39qawbFA7zMo2e6xgcYuooAcHOR54KbTCP-maneki.berries.name
ACTION: TICKET_GRANTING_TICKET_DESTROYED
APPLICATION: CAS
WHEN: Sat Nov 29 01:30:39 CET 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
Reply all
Reply to author
Forward
0 new messages