Your config appears to be executing correctly. 2015-02-24 14:20:57,866 DEBUG [org.jasig.cas.authentication.support.DefaultAccountStateHandler] - <Handling PASSWORD_MUST_CHANGE>
An AccountPasswordMustChangeException was thrown here. Something in the view layer is supposed to catch that and route the user appropriately. --Daniel Fisher On Tue, Feb 24, 2015 at 2:34 PM, Jim Price <[email protected]> wrote: > From another user shows more but no display on resultant page. > > 2015-02-24 14:20:57,865 DEBUG > [org.jasig.cas.authentication.LdapAuthenticationHandler] - <LDAP response: > [org.ldaptive.auth.AuthenticationResponse@1040133899::authenticationResultCode=AUTHENTICATION_HANDLER_FAILURE, > ldapEntry=[dn=CN=C,,DC=g,DC=edu[]], > accountState=[org.ldaptive.auth.ext.ActiveDirectoryAccountState@1013553913::accountWarnings=null, > accountErrors=[PASSWORD_MUST_CHANGE]], result=false, > resultCode=INVALID_CREDENTIALS, > message=javax.naming.AuthenticationException: [LDAP: error code 49 - > 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error, > data 773, v1db1], controls=null]> > 2015-02-24 14:20:57,866 DEBUG > [org.jasig.cas.authentication.LdapAuthenticationHandler] - <Applying > password policy to > [org.ldaptive.auth.AuthenticationResponse@1040133899::authenticationResultCode=AUTHENTICATION_HANDLER_FAILURE, > ldapEntry=[dn=CN=C,OU=S,DC=ad,DC=g,DC=edu[]], > accountState=[org.ldaptive.auth.ext.ActiveDirectoryAccountState@1013553913::accountWarnings=null, > accountErrors=[PASSWORD_MUST_CHANGE]], result=false, > resultCode=INVALID_CREDENTIALS, > message=javax.naming.AuthenticationException: [LDAP: error code 49 - > 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error, > data 773, v1db1], controls=null]> > 2015-02-24 14:20:57,866 DEBUG > [org.jasig.cas.authentication.support.DefaultAccountStateHandler] - > <Handling PASSWORD_MUST_CHANGE> > 2015-02-24 14:20:57,866 INFO > [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - > <LdapAuthenticationHandler failed authenticating cs02357+password> > 2015-02-24 14:20:57,869 INFO > [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit > trail record BEGIN > > > On Tue, Feb 24, 2015 at 1:46 PM, Jim Price <[email protected]> > wrote: > >> I do have one "Applying password policy to" >> [org.ldaptive.auth.AuthenticationResponse@1232349453::authenticationResultCode=AUTHENTICATION_HANDLER_SUCCESS, >> ldapEntry= >> one long line ...... >> >> >> On Tue, Feb 24, 2015 at 1:38 PM, Jim Price <[email protected]> >> wrote: >> >>> In advance I thank you for all of your help. >>> >>> from cas.log: same info in catalina.out >>> >>> 2015-02-24 13:18:35,792 DEBUG >>> [org.jasig.cas.web.view.CasReloadableMessageBundle] - No properties file >>> found for [classpath:custom_messages_en] - neither plain properties nor XML >>> 2015-02-24 13:18:35,793 DEBUG >>> [org.jasig.cas.web.view.CasReloadableMessageBundle] - No properties file >>> found for [classpath:custom_messages] - neither plain properties nor XML >>> 2015-02-24 13:18:35,796 DEBUG >>> [org.jasig.cas.web.view.CasReloadableMessageBundle] - No properties file >>> found for [classpath:messages_en] - neither plain properties nor XML >>> 2015-02-24 13:18:35,799 DEBUG >>> [org.jasig.cas.web.view.CasReloadableMessageBundle] - Loading properties >>> [messages.properties] with encoding 'UTF-8' >>> 2015-02-24 13:18:42,828 INFO >>> [org.jasig.cas.web.flow.InitialFlowSetupAction] - Setting path for cookies >>> to: /cas/ >>> 2015-02-24 13:18:42,828 INFO >>> [org.jasig.cas.web.flow.InitialFlowSetupAction] - Setting path for cookies >>> to: /cas/ >>> 2015-02-24 13:18:42,829 DEBUG >>> [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor did not >>> generate service. >>> 2015-02-24 13:18:42,870 DEBUG >>> [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor did not >>> generate service. >>> 2015-02-24 13:18:51,972 DEBUG >>> [org.jasig.cas.authentication.LdapAuthenticationHandler] - Attempting LDAP >>> authentication for uname+password >>> 2015-02-24 13:18:52,041 DEBUG >>> [org.jasig.cas.authentication.LdapAuthenticationHandler] - LDAP response: >>> ... >>> ... >>> responseControls=null, messageId=-1], accountState=null, result=true, >>> resultCode=SUCCESS, message=null, controls=null] >>> >>> >>> 2015-02-24 13:18:52,063 INFO >>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>> LdapAuthenticationHandler successfully authenticated uname+password >>> 2015-02-24 13:18:52,066 DEBUG >>> [org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver] - >>> Attempting to resolve a principal... >>> 2015-02-24 13:18:52,066 DEBUG >>> [org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver] - >>> Creating SimplePrincipal for [uname] >>> 2015-02-24 13:18:52,067 DEBUG >>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>> org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver@206e141d >>> resolved uname from uname+password >>> 2015-02-24 13:18:52,074 INFO >>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>> Authenticated uname with credentials [uname+password]. >>> 2015-02-24 13:18:52,074 DEBUG >>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - Attribute >>> map for uname: {uid=uid, eduPersonAffiliation=eduPersonAffiliation, >>> groupMembership=groupMembership} >>> 2015-02-24 13:18:52,079 INFO >>> [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit >>> trail record BEGIN >>> ============================================================= >>> WHO: audit:unknown >>> WHAT: supplied credentials: [uname+password] >>> ACTION: AUTHENTICATION_SUCCESS >>> APPLICATION: CAS >>> WHEN: Tue Feb 24 13:18:52 GMT-05:00 2015 >>> CLIENT IP ADDRESS: 10.01.10.10 >>> SERVER IP ADDRESS: 10.10.10.10 >>> ============================================================= >>> >>> >>> 2015-02-24 13:18:52,096 DEBUG >>> [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - Adding ticket >>> granting ticket >>> TGT-1-mqJacaHpfE3dY1EaAPdR9plIfrOEXeerTKduvoaB6jmASsR1rs-gsd1v-casaut003.cc.georgiasouthern.edu >>> to the cache cas_tgt >>> 2015-02-24 13:18:52,116 INFO >>> [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit >>> trail record BEGIN >>> ============================================================= >>> WHO: audit:unknown >>> WHAT: >>> TGT-1-mqJacaHpfE3dY1EaAPdR9plIfrOEXeerTKduvoaB6jmASsR1rs-gsd1v-casaut003.cc.georgiasouthern.edu >>> ACTION: TICKET_GRANTING_TICKET_CREATED >>> APPLICATION: CAS >>> WHEN: Tue Feb 24 13:18:52 GMT-05:00 2015 >>> CLIENT IP ADDRESS: 10.10.10.10 >>> SERVER IP ADDRESS: 10.10.10.10 >>> ============================================================= >>> >>> >>> 2015-02-24 13:18:52,119 DEBUG >>> [org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - Removed >>> cookie with name [CASPRIVACY] >>> 2015-02-24 13:18:52,132 DEBUG >>> [org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - Added cookie >>> with name [CASTGC] and value [ >>> TGT-1-mqJacaHpfE3dY1EaAPdR9plIfrOEXeerTKduvoaB6jmASsR1rs-gsd1v-casaut003.cc.georgiasouthern.edu >>> ] >>> 2015-02-24 13:18:52,150 DEBUG >>> [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor did not >>> generate service. >>> 2015-02-24 13:19:03,103 INFO >>> [org.jasig.cas.util.AutowiringSchedulerFactoryBean] - Shutting down Quartz >>> Scheduler >>> >>> >>> On Tue, Feb 24, 2015 at 12:59 PM, Misagh Moayyed <[email protected]> >>> wrote: >>> >>>> Make this change please and run the tests again: >>>> >>>> >>>> >>>> <logger name="org.jasig" additivity="true"> >>>> >>>> <level value="*DEBUG*" /> >>>> >>>> <appender-ref ref="cas" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> >>>> >>>> *From:* Jim Price [mailto:[email protected]] >>>> *Sent:* Tuesday, February 24, 2015 10:33 AM >>>> *To:* [email protected] >>>> *Subject:* Re: [cas-user] cas 4 lppe configuration for password >>>> >>>> >>>> >>>> I added the logger Daniel suggested. This is what I have in my logger. >>>> Below is a snippet from the catalina.out. There is also a cas.log but it >>>> looks to be the same as whats in the catalina.out file. >>>> >>>> >>>> >>>> >>>> >>>> <logger name="org.ldaptive.control"> >>>> >>>> <level value="WARN" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <logger name="org.springframework"> >>>> >>>> <level value="WARN" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <logger name="org.springframework.beans"> >>>> >>>> <level value="DEBUG" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <logger name="org.springframework.webflow"> >>>> >>>> <level value="WARN" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <logger name="org.jasig.cas.authentiction"> >>>> >>>> <level value="DEBUG" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <logger name="org.jasig" additivity="true"> >>>> >>>> <level value="INFO" /> >>>> >>>> <appender-ref ref="cas" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <logger >>>> name="com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager"> >>>> >>>> <level value="INFO" /> >>>> >>>> <appender-ref ref="cas" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> <!-- >>>> >>>> WARNING: Setting the flow package to DEBUG will display >>>> >>>> the parameters posted to the login servlet including >>>> >>>> cleartext authentication credentials >>>> >>>> --> >>>> >>>> <logger name="org.jasig.cas.web.flow" additivity="true"> >>>> >>>> <level value="INFO" /> >>>> >>>> <appender-ref ref="cas" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>>> 2015-02-24 12:19:20,866 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Eagerly caching bean 'cas2ServiceFailureView' to allow for resolving >>>> potential circular references> >>>> >>>> 2015-02-24 12:19:20,869 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Invoking afterPropertiesSet() on bean with name 'cas2ServiceFailureView'> >>>> >>>> 2015-02-24 12:19:20,869 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Finished creating instance of bean 'cas2ServiceFailureView'> >>>> >>>> 2015-02-24 12:19:20,869 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Creating shared instance of singleton bean 'postResponseView'> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Creating instance of bean 'postResponseView'> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Eagerly caching bean 'postResponseView' to allow for resolving potential >>>> circular references> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Invoking afterPropertiesSet() on bean with name 'postResponseView'> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Finished creating instance of bean 'postResponseView'> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Creating shared instance of singleton bean 'openIdProviderView'> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Creating instance of bean 'openIdProviderView'> >>>> >>>> 2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Eagerly caching bean 'openIdProviderView' to allow for resolving potential >>>> circular references>2015-02-24 12:19:20,871 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Eagerly caching bean 'openIdProviderView' to allow for resolving potential >>>> circular references> >>>> >>>> 2015-02-24 12:19:20,872 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Invoking afterPropertiesSet() on bean with name 'openIdProviderView'> >>>> >>>> 2015-02-24 12:19:20,872 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Finished creating instance of bean 'openIdProviderView'> >>>> >>>> 2015-02-24 12:19:20,872 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Returning cached instance of singleton bean 'lifecycleProcessor'> >>>> >>>> 2015-02-24 12:19:20,872 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Returning cached instance of singleton bean 'casLoginView'> >>>> >>>> 2015-02-24 12:19:20,921 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Returning cached instance of singleton bean 'authenticationViaFormAction'> >>>> >>>> 2015-02-24 12:19:20,953 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Returning cached instance of singleton bean 'authenticationViaFormAction'> >>>> >>>> 2015-02-24 12:19:21,008 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Returning cached instance of singleton bean 'auditTrailManagementAspect'> >>>> >>>> 2015-02-24 12:19:21,009 DEBUG >>>> [org.springframework.beans.factory.support.DefaultListableBeanFactory] - >>>> <Returning cached instance of singleton bean 'timingAspect'> >>>> >>>> 2015-02-24 12:19:21,092 INFO >>>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>>> <LdapAuthenticationHandler successfully authenticated jwprice+password> >>>> >>>> 2015-02-24 12:19:21,098 INFO >>>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>>> <Authenticated jwprice with credentials [jwprice+password].> >>>> >>>> 2015-02-24 12:19:21,110 INFO >>>> [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit >>>> trail record BEGIN >>>> >>>> 2015-02-24 12:19:21,110 INFO >>>> [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit >>>> trail record BEGIN >>>> >>>> ============================================================= >>>> >>>> WHO: audit:unknown >>>> >>>> WHAT: supplied credentials: [username+password] >>>> >>>> ACTION: AUTHENTICATION_SUCCESS >>>> >>>> APPLICATION: CAS >>>> >>>> WHEN: Tue Feb 24 12:19:21 GMT-05:00 2015 >>>> >>>> CLIENT IP ADDRESS: 10.16.3.55 >>>> >>>> SERVER IP ADDRESS: 10.16.3.98 >>>> >>>> ============================================================= >>>> >>>> >>>> >>>> > >>>> >>>> 2015-02-24 12:19:21,155 INFO >>>> [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit >>>> trail record BEGIN >>>> >>>> ============================================================= >>>> >>>> WHO: audit:unknown >>>> >>>> WHAT: >>>> TGT-1-3NuKYoPc47BE1RekAtt5qCagEqKdEieVLBhCmIOVnTx41w1fIe-gsd1v-casaut003.cc.georgiasouthern.edu >>>> >>>> ACTION: TICKET_GRANTING_TICKET_CREATED >>>> >>>> APPLICATION: CAS >>>> >>>> WHEN: Tue Feb 24 12:19:21 GMT-05:00 2015 >>>> >>>> CLIENT IP ADDRESS: 10.16.3.18 >>>> >>>> SERVER IP ADDRESS: 10.16 3.98 >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>>> On Tue, Feb 24, 2015 at 11:50 AM, Daniel Fisher <[email protected]> wrote: >>>> >>>> Do you have a logger defined for "org.jasig.cas.authentication" ? >>>> >>>> What logs are you seeing from any of the CAS components? >>>> >>>> >>>> >>>> --Daniel Fisher >>>> >>>> >>>> >>>> On Tue, Feb 24, 2015 at 9:31 AM, Jim Price <[email protected]> >>>> wrote: >>>> >>>> I've set the logger to the following value get more in the logs but not >>>> the Applying verse. What do you mean by a Spring Wiring issue? I know it >>>> gets to the spring-configuration directory because my ldap.properties was >>>> recognized after editing propertyFileConfigurer.xml. >>>> >>>> When starting tomcat I see the system read this file though a >>>> strace: lppe-configuration.xml. It actually opens all xml files in >>>> spring-configuration directory. Any ideas on how I could track this down? >>>> >>>> >>>> >>>> <logger name="org.springframework"> >>>> >>>> <level value="DEBUG" /> >>>> >>>> </logger> >>>> >>>> >>>> >>>> Is there a way maven can be setup to read these files and the tomcat >>>> environment not? >>>> >>>> >>>> >>>> On Mon, Feb 23, 2015 at 5:09 PM, Daniel Fisher <[email protected]> wrote: >>>> >>>> On Mon, Feb 23, 2015 at 4:49 PM, Jim Price <[email protected]> >>>> wrote: >>>> >>>> I do not see "Applying password policy to" in my logs anywhere. >>>> >>>> >>>> >>>> Then you have a Spring wiring issue or a logging issue. >>>> >>>> >>>> >>>> >>>> https://github.com/Jasig/cas/blob/v4.0.0/cas-server-support-ldap/src/main/java/org/jasig/cas/authentication/LdapAuthenticationHandler.java#L172 >>>> >>>> >>>> >>>> --Daniel Fisher >>>> >>>> >>>> >>>> -- >>>> >>>> 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 >>>> >>>> >>>> >>>> -- >>>> >>>> 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 >>>> >>>> -- >>>> 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 > > -- 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
