I turned up debug logging and this is the resulting log.
2014-01-29 09:38:25,791 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Reloading registered services.
2014-01-29 09:38:25,791 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Loaded 1 services.
2014-01-29 09:40:25,786 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Reloading registered services.
2014-01-29 09:40:25,786 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Loaded 1 services.
2014-01-29 09:42:25,782 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Reloading registered services.
2014-01-29 09:42:25,782 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Loaded 1 services.
2014-01-29 09:44:25,793 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Reloading registered services.
2014-01-29 09:44:25,793 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Loaded 1 services.
2014-01-29 09:45:17,242 INFO [org.jasig.cas.util.AutowiringSchedulerFactoryBean] - Shutting down Quartz Scheduler
2014-01-29 09:45:31,921 DEBUG [org.jasig.cas.services.DefaultServicesManagerImpl] - Adding registered service ^(https?|imaps?)://.*
2014-01-29 09:45:31,921 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - Loaded 1 services.
2014-01-29 09:45:32,436 DEBUG [org.jasig.cas.util.AutowiringSchedulerFactoryBean] - Autowired the following triggers defined in application context: [triggerJobDetailTicketRegistryCleaner, periodicServiceRegistryReloaderTrigger]
2014-01-29 09:45:33,450 INFO [org.jasig.cas.util.AutowiringSchedulerFactoryBean] - Starting Quartz Scheduler now
2014-01-29 09:45:33,918 DEBUG [org.jasig.cas.services.web.ManageRegisteredServicesMultiActionController] - Found action method [public org.springframework.web.servlet.ModelAndView org.jasig.cas.services.web.ManageRegisteredServicesMultiActionController.updateRegisteredServiceEvaluationOrder(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)]
2014-01-29 09:45:33,918 DEBUG [org.jasig.cas.services.web.ManageRegisteredServicesMultiActionController] - Found action method [public org.springframework.web.servlet.ModelAndView org.jasig.cas.services.web.ManageRegisteredServicesMultiActionController.deleteRegisteredService(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)]
2014-01-29 09:45:33,918 DEBUG [org.jasig.cas.services.web.ManageRegisteredServicesMultiActionController] - Found action method [public org.springframework.web.servlet.ModelAndView org.jasig.cas.services.web.ManageRegisteredServicesMultiActionController.manage(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)]
2014-01-29 09:45:35,915 INFO [org.jasig.cas.web.flow.InitialFlowSetupAction] - Setting path for cookies to: /cas-server-webapp-3.5.2/
2014-01-29 09:45:35,915 INFO [org.jasig.cas.web.flow.InitialFlowSetupAction] - Setting path for cookies to: /cas-server-webapp-3.5.2/
2014-01-29 09:45:35,915 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor did not generate service.
2014-01-29 09:45:35,915 DEBUG [org.jasig.cas.web.support.SamlArgumentExtractor] - Extractor did not generate service.
2014-01-29 09:45:38,255 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor did not generate service.
2014-01-29 09:45:38,255 DEBUG [org.jasig.cas.web.support.SamlArgumentExtractor] - Extractor did not generate service.
2014-01-29 09:45:51,406 INFO [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - Beginning ticket cleanup.
2014-01-29 09:45:51,406 DEBUG [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - Attempting to acquire ticket cleanup lock.
2014-01-29 09:45:51,406 DEBUG [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - Acquired lock. Proceeding with cleanup.
2014-01-29 09:45:51,406 INFO [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - 0 tickets found to be removed.
2014-01-29 09:45:51,406 DEBUG [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - Releasing ticket cleanup lock.
2014-01-29 09:45:51,406 INFO [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - Finished ticket cleanup.
2014-01-29 09:45:55,212 INFO [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: [username: mattsimmons2]
WHAT: 'principal' cannot be null.
Check the correctness of @Audit annotation at the following audit point: execution(public abstract org.jasig.cas.authentication.Authentication org.jasig.cas.authentication.AuthenticationManager.authenticate(org.jasig.cas.authentication.principal.Credentials))
ACTION: TICKET_GRANTING_TICKET_NOT_CREATED
APPLICATION: CAS
WHEN: Wed Jan 29 09:45:55 CST 2014
CLIENT IP ADDRESS: 192.168.101.55
SERVER IP ADDRESS: 192.168.101.55
=============================================================
2014-01-29 09:45:55,228 DEBUG [org.jasig.cas.web.FlowExecutionExceptionResolver] - Ignoring the received exception due to a type mismatch
org.springframework.webflow.execution.ActionExecutionException: Exception thrown executing [AnnotatedAction@620ecdd4 targetAction = [EvaluateAction@39eb4b97 expression = authenticationViaFormAction.submit(flowRequestContext, flowScope.credentials, messageContext), resultExpression = [null]], attributes = map[[empty]]] in state 'realSubmit' of flow 'login' -- action execution attributes were 'map[[empty]]'
at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:60)
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.Transition.execute(Transition.java:227)
at org.springframework.webflow.engine.impl.FlowExecutionImpl.execute(FlowExecutionImpl.java:393)
at org.springframework.webflow.engine.impl.RequestControlContextImpl.execute(RequestControlContextImpl.java:214)
at org.springframework.webflow.engine.TransitionableState.handleEvent(TransitionableState.java:119)
at org.springframework.webflow.engine.Flow.handleEvent(Flow.java:555)
at org.springframework.webflow.engine.impl.FlowExecutionImpl.handleEvent(FlowExecutionImpl.java:388)
at org.springframework.webflow.engine.impl.RequestControlContextImpl.handleEvent(RequestControlContextImpl.java:210)
at org.springframework.webflow.engine.ViewState.handleEvent(ViewState.java:232)
at org.springframework.webflow.engine.ViewState.resume(ViewState.java:196)
at org.springframework.webflow.engine.Flow.resume(Flow.java:545)
at org.springframework.webflow.engine.impl.FlowExecutionImpl.resume(FlowExecutionImpl.java:261)
at org.springframework.webflow.executor.FlowExecutorImpl.resumeExecution(FlowExecutorImpl.java:169)
at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:183)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:789)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
at org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody2(SafeDispatcherServlet.java:128)
at org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody3$advice(SafeDispatcherServlet.java:57)
at org.jasig.cas.web.init.SafeDispatcherServlet.service(SafeDispatcherServlet.java:1)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
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:346)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at com.github.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:63)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:409)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:315)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.springframework.binding.expression.EvaluationException: An OgnlException occurred getting the value for expression 'authenticationViaFormAction.submit(flowRequestContext, flowScope.credentials, messageContext)' on context [class org.springframework.webflow.engine.impl.RequestControlContextImpl]
at org.springframework.binding.expression.ognl.OgnlExpression.getValue(OgnlExpression.java:92)
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)
... 52 more
Caused by: ognl.MethodFailedException: Method "submit" failed for object org.jasig.cas.web.flow.AuthenticationViaFormAction@78d96b4b [java.lang.IllegalArgumentException: 'principal' cannot be null.
Check the correctness of @Audit annotation at the following audit point: execution(public abstract org.jasig.cas.authentication.Authentication org.jasig.cas.authentication.AuthenticationManager.authenticate(org.jasig.cas.authentication.principal.Credentials))]
at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:1265)
at ognl.ObjectMethodAccessor.callMethod(ObjectMethodAccessor.java:68)
at ognl.OgnlRuntime.callMethod(OgnlRuntime.java:1329)
at ognl.ASTMethod.getValueBody(ASTMethod.java:90)
at ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:212)
at ognl.SimpleNode.getValue(SimpleNode.java:258)
at ognl.ASTChain.getValueBody(ASTChain.java:141)
at ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:212)
at ognl.SimpleNode.getValue(SimpleNode.java:258)
at ognl.Ognl.getValue(Ognl.java:494)
at org.springframework.binding.expression.ognl.OgnlExpression.getValue(OgnlExpression.java:85)
... 56 more
Caused by: java.lang.IllegalArgumentException: 'principal' cannot be null.
Check the correctness of @Audit annotation at the following audit point: execution(public abstract org.jasig.cas.authentication.Authentication org.jasig.cas.authentication.AuthenticationManager.authenticate(org.jasig.cas.authentication.principal.Credentials))
at com.github.inspektr.audit.AuditActionContext.assertNotNull(AuditActionContext.java:81)
at com.github.inspektr.audit.AuditActionContext.<init>(AuditActionContext.java:63)
at com.github.inspektr.audit.AuditTrailManagementAspect.executeAuditCode(AuditTrailManagementAspect.java:149)
at com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:139)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
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.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy24.authenticate(Unknown Source)
at org.jasig.cas.CentralAuthenticationServiceImpl.createTicketGrantingTicket_aroundBody10(CentralAuthenticationServiceImpl.java:477)
at org.jasig.cas.CentralAuthenticationServiceImpl.createTicketGrantingTicket_aroundBody11$advice(CentralAuthenticationServiceImpl.java:57)
at org.jasig.cas.CentralAuthenticationServiceImpl.createTicketGrantingTicket(CentralAuthenticationServiceImpl.java:1)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
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(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
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 com.github.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:126)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
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.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy25.createTicketGrantingTicket(Unknown Source)
at org.jasig.cas.web.flow.AuthenticationViaFormAction.submit_aroundBody2(AuthenticationViaFormAction.java:109)
at org.jasig.cas.web.flow.AuthenticationViaFormAction.submit_aroundBody3$advice(AuthenticationViaFormAction.java:57)
at org.jasig.cas.web.flow.AuthenticationViaFormAction.submit(AuthenticationViaFormAction.java:1)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:830)
at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:1253)
... 66 more
2014-01-29 09:45:55,243 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor did not generate service.
2014-01-29 09:45:55,243 DEBUG [org.jasig.cas.web.support.SamlArgumentExtractor] - Extractor did not generate service.
Matt Simmons
-----Original Message-----
From: Marvin Addison [mailto:
marvin....@gmail.com]
Sent: Wednesday, January 29, 2014 9:19 AM
To:
cas-...@lists.jasig.org
Subject: Re: [cas-user] Problem with CAS implementation
> I'm installing CAS in Tomcat7 on Windows Server 2008.
I know folks run Tomcat on Windows but I would say it's uncommon. Off the top of my head I would think SSL trust configuration might be a trouble spot.
> Here is the cas.log when I try to login....
> 2014-01-29 08:47:58,387 INFO
> [org.jasig.cas.services.DefaultServicesManagerImpl] - Loaded 1 services.
Not enough information here. Turn the logging up to DEBUG and retry, then post the debug logs. I'm thinking there may be a problem with principal resolution against your SQL server database. The root cause could be any number of things, but more verbose logs should help paint a clearer picture.
M
--
You are currently subscribed to
cas-...@lists.jasig.org as:
msim...@edocamerica.com To unsubscribe, change settings or access archives, see
http://www.ja-sig.org/wiki/display/JSG/cas-user