SAML response problem

Scott Battaglia scott.battaglia at gmail.com
Tue Jan 20 11:51:00 EST 2009 

You may be checking an assertion that is not yet valid:

2009-01-19 15:39:35,148 DEBUG
[org.jasig.cas.client.validation.Saml11TicketValidator] - skipping
assertion that's not yet valid...

Not sure if that's a problem on the client or server side.

-Scott

-Scott Battaglia
PGP Public Key Id: 0x383733AA
LinkedIn: http://www.linkedin.com/in/scottbattaglia


On Tue, Jan 20, 2009 at 9:45 AM, Julien Gribonvald <
julien.gribonvald at recia.fr> wrote:

> Hi,
>
> I don't think this come from these 2 points, i checked all and it seems
> correct, I have validation from CAS when the client request the
> validation... But maybe this come from special caracters in the url ?
>
> Else what do you need more ? I join the file log of cas...
>
> thanks
>
> Julien G.
>
> Scott Battaglia a écrit :
>
>> Hi,
>>
>> In general its one of two problems (and we should probably make the error
>> message clearer ;-)): either there is a certificate error, or the validation
>> url was specified incorrectly (the CAS client only requires the point up to
>> CAS, i.e. https://my.server.com/cas).
>>
>> If both those are okay, we'll need to see if we can get any more info.
>>
>> -Scott
>>
>> -Scott Battaglia
>> PGP Public Key Id: 0x383733AA
>> LinkedIn: http://www.linkedin.com/in/scottbattaglia
>>
>>
>> On Mon, Jan 19, 2009 at 10:51 AM, Julien Gribonvald <
>> julien.gribonvald at recia.fr <mailto:julien.gribonvald at recia.fr>> wrote:
>>
>>    Hi,
>>
>>    I'm looking for help to understand a problem of SAML talk between CAS
>>    server ( 3.3.1 with cas toolbox) and CAS client (3.3.1).
>>
>>    The CAS server is deployed on a tomcat 6.0.16 and java 1.5.0_10,
>>    and the
>>    app is on a tomcat 5.5.27 with java 1.5.0_14 and all is behind an
>>    appache with mod_jk.
>>
>>    On cas log I have only this warning :
>>    2009-01-19 15:59:54,258 WARN [org.opensaml.XML] - Unable to turn off
>>    data normalization in parser, supersignatures may fail with Xerces-J:
>>    javax.xml.parsers.ParserConfigurationException:
>>    jaxp_feature_not_supported: Feature
>>    "http://apache.org/xml/features/validation/schema/normalized-value" is
>>    not supported.
>>
>>
>>    And when the app client try to validate a ticket with SAML protocol it
>>    succeed, but I get this error :
>>
>>    2009-01-19 15:39:21,048 DEBUG
>>    [org.jasig.cas.client.authentication.AuthenticationFilter] - no ticket
>>    and no assertion found
>>    2009-01-19 15:39:21,049 DEBUG
>>    [org.jasig.cas.client.util.CommonUtils] -
>>    serviceUrl generated: http://my.host.net:8080/PRONOTEsso/
>>    2009-01-19 <http://my.host.net:8080/PRONOTEsso/2009-01-19>
>>    15:39:21,049 DEBUG
>>    [org.jasig.cas.client.authentication.AuthenticationFilter] -
>>    Constructed
>>    service url: http://my.host.net:8080/PRONOTEsso/
>>    2009-01-19 <http://my.host.net:8080/PRONOTEsso/2009-01-19>
>>    15:39:21,049 DEBUG
>>    [org.jasig.cas.client.authentication.AuthenticationFilter] -
>>    redirecting
>>    to
>>    "
>> https://dvorak.recia.fr/cas/login?service=http%3A%2F%2Fmy.host.net%3A8080%2FPRONOTEsso%2F
>> "
>>    2009-01-19 15:39:34,785 DEBUG
>>    [org.jasig.cas.client.authentication.AuthenticationFilter] - removing
>>    gateway attribute from session
>>    2009-01-19 15:39:34,785 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidationFilter] -
>>    Attempting to validate ticket: ST-1-EP4Is7yga1cbkdFY50Zv-cas
>>    2009-01-19 15:39:34,786 DEBUG
>>    [org.jasig.cas.client.util.CommonUtils] -
>>    serviceUrl generated: http://my.host.net:8080/PRONOTEsso/
>>    2009-01-19 <http://my.host.net:8080/PRONOTEsso/2009-01-19>
>>    15:39:34,786 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - Placing URL
>>    parameters in map.
>>    2009-01-19 15:39:34,786 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - Calling
>>    template URL attribute map.
>>    2009-01-19 15:39:34,786 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - Loading
>>    custom
>>    parameters from configuration.
>>    2009-01-19 15:39:34,786 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - Constructing
>>    validation url:
>>
>> https://dvorak.recia.fr/cas/samlValidate?TARGET=http%3A%2F%2Fmy.host.net%3A8080%2FPRONOTEsso%2F
>>    2009-01-19
>>    <
>> https://dvorak.recia.fr/cas/samlValidate?TARGET=http%3A%2F%2Fmy.host.net%3A8080%2FPRONOTEsso%2F2009-01-19
>> >
>>
>>    15:39:34,786 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - Retrieving
>>    response from server.
>>    2009-01-19 15:39:35,141 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - Server
>>    response: <?xml version="1.0" encoding="UTF-8"?><SOAP-ENV:Envelope
>>    xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/
>> "><SOAP-ENV:Header/><SOAP-ENV:Body><Response
>>    xmlns="urn:oasis:names:tc:SAML:1.0:protocol"
>>    xmlns:saml="urn:oasis:names:tc:SAML:1.0:assertion"
>>    xmlns:samlp="urn:oasis:names:tc:SAML:1.0:protocol"
>>    xmlns:xsd="http://www.w3.org/2001/XMLSchema"
>>    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
>>    IssueInstant="2009-01-19T14:59:54.088Z" MajorVersion="1"
>>    MinorVersion="1" Recipient="http://my.host.net:8080/PRONOTEsso/"
>>    ResponseID="_4f85a1187ad9080a4963e3bffe23728e"><Status><StatusCode
>>    Value="samlp:Success"></StatusCode></Status><Assertion
>>    xmlns="urn:oasis:names:tc:SAML:1.0:assertion"
>>    AssertionID="_9ca35d5f982cba06665b4ee2ac5ade0e"
>>    IssueInstant="2009-01-19T14:59:54.088Z" Issuer="localhost"
>>    MajorVersion="1" MinorVersion="1"><Conditions
>>    NotBefore="2009-01-19T14:59:54.088Z"
>>
>>  NotOnOrAfter="2009-01-19T15:00:24.088Z"><AudienceRestrictionCondition><Audience>
>> http://my.host.net:8080/PRONOTEsso/
>> </Audience></AudienceRestrictionCondition></Conditions><AttributeStatement><Subject><NameIdentifier>F08001pi</NameIdentifier><SubjectConfirmation><ConfirmationMethod>urn:oasis:names:tc:SAML:1.0:cm:artifact</ConfirmationMethod></SubjectConfirmation></Subject><Attribute
>>    AttributeName="dateNaissance"
>>    AttributeNamespace="http://www.ja-sig.org/products/cas/
>> "><AttributeValue>04/05/1983</AttributeValue></Attribute><Attribute
>>    AttributeName="user"
>>    AttributeNamespace="http://www.ja-sig.org/products/cas/
>> "><AttributeValue>F08001pi</AttributeValue></Attribute><Attribute
>>    AttributeName="login"
>>    AttributeNamespace="http://www.ja-sig.org/products/cas/
>> "><AttributeValue>julien.gribonvald</AttributeValue></Attribute><Attribute
>>    AttributeName="prenom"
>>    AttributeNamespace="http://www.ja-sig.org/products/cas/
>> "><AttributeValue>Julien</AttributeValue></Attribute><Attribute
>>    AttributeName="nom"
>>    AttributeNamespace="http://www.ja-sig.org/products/cas/
>> "><AttributeValue>GRIBONVALD</AttributeValue></Attribute></AttributeStatement><AuthenticationStatement
>>    AuthenticationInstant="2009-01-19T14:59:54.001Z"
>>
>>  AuthenticationMethod="urn:oasis:names:tc:SAML:1.0:am:unspecified"><Subject><NameIdentifier>F08001pi</NameIdentifier><SubjectConfirmation><ConfirmationMethod>urn:oasis:names:tc:SAML:1.0:cm:artifact</ConfirmationMethod></SubjectConfirmation></Subject></AuthenticationStatement></Assertion></Response></SOAP-ENV:Body></SOAP-ENV:Envelope>
>>    2009-01-19 15:39:35,148 DEBUG
>>    [org.jasig.cas.client.validation.Saml11TicketValidator] - skipping
>>    assertion that's not yet valid...
>>    2009-01-19 15:39:35,148 WARN
>>    [org.jasig.cas.client.validation.Saml11TicketValidationFilter] -
>>    org.jasig.cas.client.validation.TicketValidationException: No valid
>>    assertions from the SAML response found.
>>    org.jasig.cas.client.validation.TicketValidationException: No valid
>>    assertions from the SAML response found.
>>           at
>>
>>  org.jasig.cas.client.validation.Saml11TicketValidator.parseResponseFromServer(Saml11TicketValidator.java:96)
>>           at
>>
>>  org.jasig.cas.client.validation.AbstractUrlBasedTicketValidator.validate(AbstractUrlBasedTicketValidator.java:188)
>>           at
>>
>>  org.jasig.cas.client.validation.AbstractTicketValidationFilter.doFilter(AbstractTicketValidationFilter.java:132)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
>>           at
>>
>>  org.jasig.cas.client.authentication.AuthenticationFilter.doFilter(AuthenticationFilter.java:111)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
>>           at
>>
>>  org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
>>           at
>>
>>  org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172)
>>           at
>>
>>  org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
>>           at
>>
>>  org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
>>           at
>>
>>  org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
>>           at
>>
>>  org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174)
>>           at
>>
>>  org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:875)
>>           at
>>
>>  org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
>>           at
>>
>>  org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
>>           at
>>
>>  org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
>>           at
>>
>>  org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
>>           at java.lang.Thread.run(Thread.java:595)
>>    2009-01-19 15:39:35,149 ERROR
>>
>>  [org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/PRONOTEsso].[DoServlet]]
>>    - Servlet.service() for servlet DoServlet threw exception
>>    org.jasig.cas.client.validation.TicketValidationException: No valid
>>    assertions from the SAML response found.
>>           at
>>
>>  org.jasig.cas.client.validation.Saml11TicketValidator.parseResponseFromServer(Saml11TicketValidator.java:96)
>>           at
>>
>>  org.jasig.cas.client.validation.AbstractUrlBasedTicketValidator.validate(AbstractUrlBasedTicketValidator.java:188)
>>           at
>>
>>  org.jasig.cas.client.validation.AbstractTicketValidationFilter.doFilter(AbstractTicketValidationFilter.java:132)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
>>           at
>>
>>  org.jasig.cas.client.authentication.AuthenticationFilter.doFilter(AuthenticationFilter.java:111)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
>>           at
>>
>>  org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
>>           at
>>
>>  org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
>>           at
>>
>>  org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172)
>>           at
>>
>>  org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
>>           at
>>
>>  org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
>>           at
>>
>>  org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
>>           at
>>
>>  org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174)
>>           at
>>
>>  org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:875)
>>           at
>>
>>  org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
>>           at
>>
>>  org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
>>           at
>>
>>  org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
>>           at
>>
>>  org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
>>           at java.lang.Thread.run(Thread.java:595)
>>
>>
>>
>>    Is there someone who have an idea of this problem ?
>>
>>    thanks
>>
>>    Julien G.
>>    _______________________________________________
>>    Yale CAS mailing list
>>    cas at tp.its.yale.edu <mailto:cas at tp.its.yale.edu>
>>    http://tp.its.yale.edu/mailman/listinfo/cas
>>
>>
>>
>
> 2009-01-20 15:47:41,829 INFO [org.quartz.core.QuartzScheduler] - Quartz
> Scheduler v.1.5.2 created.
> 2009-01-20 15:47:41,832 INFO [org.quartz.simpl.RAMJobStore] - RAMJobStore
> initialized.
> 2009-01-20 15:47:41,832 INFO [org.quartz.impl.StdSchedulerFactory] - Quartz
> scheduler 'scheduler' initialized from an externally provided properties
> instance.
> 2009-01-20 15:47:41,832 INFO [org.quartz.impl.StdSchedulerFactory] - Quartz
> scheduler version: 1.5.2
> 2009-01-20 15:47:41,835 INFO [org.quartz.core.QuartzScheduler] - JobFactory
> set to: org.springframework.scheduling.quartz.AdaptableJobFactory at 1021f34
> 2009-01-20 15:47:41,836 INFO [org.quartz.core.QuartzScheduler] - Scheduler
> scheduler_$_NON_CLUSTERED started.
> 2009-01-20 15:47:42,700 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)]
> 2009-01-20 15:47:42,700 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)]
> 2009-01-20 15:47:42,759 INFO
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - FormObjectClass not
> set.  Using default class of
> org.jasig.cas.authentication.principal.UsernamePasswordCredentials with
> formObjectName credentials and validator
> org.jasig.cas.validation.UsernamePasswordCredentialsValidator.
> 2009-01-20 15:48:01,772 INFO
> [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] -
> Starting cleaning of expired tickets from ticket registry at [Tue Jan 20
> 15:48:01 CET 2009]
> 2009-01-20 15:48:01,773 INFO
> [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] - 0
> found to be removed.  Removing now.
> 2009-01-20 15:48:01,773 INFO
> [org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner] -
> Finished cleaning of expired tickets from ticket registry at [Tue Jan 20
> 15:48:01 CET 2009]
> 2009-01-20 15:48:03,289 DEBUG
> [org.jasig.cas.web.flow.InitialFlowSetupAction] - Action
> 'InitialFlowSetupAction' beginning execution
> 2009-01-20 15:48:03,291 INFO
> [org.jasig.cas.web.flow.InitialFlowSetupAction] - Setting path for cookies
> to: /cas
> 2009-01-20 15:48:03,296 DEBUG
> [org.jasig.cas.web.support.CasArgumentExtractor] - Extractor generated
> service for: http://dvorak.recia.fr/PRONOTEsso/
> 2009-01-20 <http://dvorak.recia.fr/PRONOTEsso/2009-01-20> 15:48:03,296
> DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - Placing service in
> FlowScope: http://dvorak.recia.fr/PRONOTEsso/
> 2009-01-20 <http://dvorak.recia.fr/PRONOTEsso/2009-01-20> 15:48:03,296
> DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] - Action
> 'InitialFlowSetupAction' completed execution; result is 'success'
> 2009-01-20 15:48:03,318 DEBUG
> [org.jasig.cas.web.flow.GenerateServiceTicketAction] - Action
> 'GenerateServiceTicketAction' beginning execution
> 2009-01-20 15:48:03,318 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to
> retrieve ticket
> [TGT-4-Zr65nLIJueSlumSIY2rTIhPPcMzcVjdRxi2dJE9Mm1HxjMdD0D-cas]
> 2009-01-20 15:48:03,318 DEBUG
> [org.jasig.cas.web.flow.GenerateServiceTicketAction] - Action
> 'GenerateServiceTicketAction' completed execution; result is 'error'
> 2009-01-20 15:48:03,318 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' beginning execution
> 2009-01-20 15:48:03,321 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Executing setupForm
> 2009-01-20 15:48:03,321 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Creating new form
> object with name 'credentials'
> 2009-01-20 15:48:03,321 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Creating new instance
> of form object class [class
> org.jasig.cas.authentication.principal.UsernamePasswordCredentials]
> 2009-01-20 15:48:03,322 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Putting form object
> of type [class
> org.jasig.cas.authentication.principal.UsernamePasswordCredentials] in scope
> Flow with name 'credentials'
> 2009-01-20 15:48:03,322 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Creating new form
> errors for object with name 'credentials'
> 2009-01-20 15:48:03,329 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - No property editor
> registrar set, no custom editors to register
> 2009-01-20 15:48:03,332 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Putting form errors
> instance in scope Flash
> 2009-01-20 15:48:03,332 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' completed execution; result is 'success'
> 2009-01-20 15:48:03,332 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' beginning execution
> 2009-01-20 15:48:03,333 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' completed execution; result is 'success'
> 2009-01-20 15:48:19,035 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' beginning execution
> 2009-01-20 15:48:19,035 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Executing bind
> 2009-01-20 15:48:19,035 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Found existing form
> object with name 'credentials' of type [class
> org.jasig.cas.authentication.principal.UsernamePasswordCredentials] in scope
> Flow
> 2009-01-20 15:48:19,035 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - No property editor
> registrar set, no custom editors to register
> 2009-01-20 15:48:19,038 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Binding allowed
> request parameters in map['lt' ->
> '_c69A8CE59-D5E4-73FB-11B0-D37CC48A872F_kB68FBB1C-3E18-2FA0-5BE3-01BC59B072C8',
> 'service' -> 'http://dvorak.recia.fr/PRONOTEsso/', '_eventId' -> 'submit',
> 'password' -> 'XXXXXXX', 'submit.y' -> '13', 'submit.x' -> '22', 'username'
> -> 'julien.gribonvald'] to form object with name 'credentials', pre-bind
> formObject toString = [username: null]
> 2009-01-20 15:48:19,038 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - (Any field is
> allowed)
> 2009-01-20 15:48:19,041 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Binding completed for
> form object with name 'credentials', post-bind formObject toString =
> [username: julien.gribonvald]
> 2009-01-20 15:48:19,041 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - There are [0] errors,
> details: []
> 2009-01-20 15:48:19,041 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Executing validation
> 2009-01-20 15:48:19,042 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Invoking validator
> org.jasig.cas.validation.UsernamePasswordCredentialsValidator at 1f2be27
> 2009-01-20 15:48:19,043 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Validation completed
> for form object
> 2009-01-20 15:48:19,043 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - There are [0] errors,
> details: []
> 2009-01-20 15:48:19,043 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Putting form errors
> instance in scope Flash
> 2009-01-20 15:48:19,044 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' completed execution; result is 'success'
> 2009-01-20 15:48:19,044 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' beginning execution
> 2009-01-20 15:48:19,044 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Found existing form
> object with name 'credentials' of type [class
> org.jasig.cas.authentication.principal.UsernamePasswordCredentials] in scope
> Flow
> 2009-01-20 15:48:19,044 DEBUG
> [org.jasig.cas.CentralAuthenticationServiceImpl] - Attempting to create
> TicketGrantingTicket for [username: julien.gribonvald]
> 2009-01-20 15:48:19,074 INFO
> [org.jasig.cas.authentication.AuthenticationManagerImpl] -
> AuthenticationHandler:
> org.jasig.cas.adaptors.ldap.BindLdapAuthenticationHandler successfully
> authenticated the user which provided the following credentials: [username:
> julien.gribonvald]
> 2009-01-20 15:48:19,074 DEBUG
> [org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
> - Attempting to resolve a principal...
> 2009-01-20 15:48:19,074 DEBUG
> [org.jasig.cas.authentication.principal.UsernamePasswordCredentialsToPrincipalResolver]
> - Attempting to resolve a principal...
> 2009-01-20 15:48:19,074 DEBUG
> [org.jasig.cas.authentication.principal.UsernamePasswordCredentialsToPrincipalResolver]
> - Creating SimplePrincipal for [julien.gribonvald]
> 2009-01-20 15:48:19,075 DEBUG
> [org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao] - Created
> seed map='{username=[julien.gribonvald]}' for uid='julien.gribonvald'
> 2009-01-20 15:48:19,075 DEBUG
> [org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao] -
> Constructed argument array '[[julien.gribonvald]]' from the
> defaultAttributeName='username'
> 2009-01-20 15:48:19,085 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'ENTPersonDateNaissance' from byte[] to
> String
> 2009-01-20 15:48:19,086 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[dateNaissance, ENTPersonDateNaissance]' for
> source attribute 'ENTPersonDateNaissance'
> 2009-01-20 15:48:19,086 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'ENTPersonLogin' from byte[] to String
> 2009-01-20 15:48:19,086 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[ENTPersonLogin, login]' for source attribute
> 'ENTPersonLogin'
> 2009-01-20 15:48:19,086 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'uid' from byte[] to String
> 2009-01-20 15:48:19,086 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[user, uid]' for source attribute 'uid'
> 2009-01-20 15:48:19,086 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'mail' from byte[] to String
> 2009-01-20 15:48:19,086 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[mail]' for source attribute 'mail'
> 2009-01-20 15:48:19,086 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'ENTPersonFonctions' from byte[] to
> String
> 2009-01-20 15:48:19,086 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 1 of LDAP attribute 'ENTPersonFonctions' from byte[] to
> String
> 2009-01-20 15:48:19,086 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 2
> attributes under mapped names '[ENTPersonFonctions]' for source attribute
> 'ENTPersonFonctions'
> 2009-01-20 15:48:19,086 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'sn' from byte[] to String
> 2009-01-20 15:48:19,087 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[sn, nom]' for source attribute 'sn'
> 2009-01-20 15:48:19,087 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'cn' from byte[] to String
> 2009-01-20 15:48:19,087 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[cn]' for source attribute 'cn'
> 2009-01-20 15:48:19,087 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'givenName' from byte[] to String
> 2009-01-20 15:48:19,087 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[prenom, givenName]' for source attribute
> 'givenName'
> 2009-01-20 15:48:19,087 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'displayName' from byte[] to String
> 2009-01-20 15:48:19,087 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[displayName]' for source attribute
> 'displayName'
> 2009-01-20 15:48:19,094 DEBUG
> [org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
> - Resolved julien.gribonvald. Trying LDAP resolve now...
> 2009-01-20 15:48:19,094 DEBUG
> [org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
> - LDAP search with filter
> "(|(uid=julien.gribonvald)(ENTPersonLogin=julien.gribonvald))"
> 2009-01-20 15:48:19,094 DEBUG
> [org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
> - returning searchcontrols: scope=2; search
> base=ou=people,dc=esco-centre,dc=fr; attributes=[uid]; timeout=1000
> 2009-01-20 15:48:19,098 DEBUG
> [org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
> - Resolved julien.gribonvald to F08001pi
> 2009-01-20 15:48:19,098 DEBUG
> [org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
> - Creating SimplePrincipal for [F08001pi]
> 2009-01-20 15:48:19,098 DEBUG
> [org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao] - Created
> seed map='{username=[F08001pi]}' for uid='F08001pi'
> 2009-01-20 15:48:19,098 DEBUG
> [org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao] -
> Constructed argument array '[[F08001pi]]' from the
> defaultAttributeName='username'
> 2009-01-20 15:48:19,100 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'ENTPersonDateNaissance' from byte[] to
> String
> 2009-01-20 15:48:19,100 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[dateNaissance, ENTPersonDateNaissance]' for
> source attribute 'ENTPersonDateNaissance'
> 2009-01-20 15:48:19,100 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'ENTPersonLogin' from byte[] to String
> 2009-01-20 15:48:19,100 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[ENTPersonLogin, login]' for source attribute
> 'ENTPersonLogin'
> 2009-01-20 15:48:19,100 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'uid' from byte[] to String
> 2009-01-20 15:48:19,101 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[user, uid]' for source attribute 'uid'
> 2009-01-20 15:48:19,101 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'mail' from byte[] to String
> 2009-01-20 15:48:19,102 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[mail]' for source attribute 'mail'
> 2009-01-20 15:48:19,102 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'ENTPersonFonctions' from byte[] to
> String
> 2009-01-20 15:48:19,102 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 1 of LDAP attribute 'ENTPersonFonctions' from byte[] to
> String
> 2009-01-20 15:48:19,102 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 2
> attributes under mapped names '[ENTPersonFonctions]' for source attribute
> 'ENTPersonFonctions'
> 2009-01-20 15:48:19,102 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'sn' from byte[] to String
> 2009-01-20 15:48:19,102 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[sn, nom]' for source attribute 'sn'
> 2009-01-20 15:48:19,102 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'cn' from byte[] to String
> 2009-01-20 15:48:19,102 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[cn]' for source attribute 'cn'
> 2009-01-20 15:48:19,102 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'givenName' from byte[] to String
> 2009-01-20 15:48:19,103 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[prenom, givenName]' for source attribute
> 'givenName'
> 2009-01-20 15:48:19,103 WARN
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] -
> Converting value 0 of LDAP attribute 'displayName' from byte[] to String
> 2009-01-20 15:48:19,103 DEBUG
> [org.jasig.services.persondir.support.ldap.PersonAttributesMapper] - Added 1
> attributes under mapped names '[displayName]' for source attribute
> 'displayName'
> 2009-01-20 15:48:19,107 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Added ticket
> [TGT-1-tGfRQa0WAeN3Z5cODTaVMVfmPnex2oxBdKp7wWTErhWO0tpGje-cas] to registry.
> 2009-01-20 15:48:19,107 DEBUG
> [org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - Removed cookie
> with name [CASPRIVACY]
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.web.flow.AuthenticationViaFormAction] - Action
> 'AuthenticationViaFormAction' completed execution; result is 'success'
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.web.flow.SendTicketGrantingTicketAction] - Action
> 'SendTicketGrantingTicketAction' beginning execution
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - Added cookie
> with name [CASTGC] and value
> [TGT-1-tGfRQa0WAeN3Z5cODTaVMVfmPnex2oxBdKp7wWTErhWO0tpGje-cas]
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.CentralAuthenticationServiceImpl] - Removing ticket
> [TGT-4-Zr65nLIJueSlumSIY2rTIhPPcMzcVjdRxi2dJE9Mm1HxjMdD0D-cas] from
> registry.
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to
> retrieve ticket
> [TGT-4-Zr65nLIJueSlumSIY2rTIhPPcMzcVjdRxi2dJE9Mm1HxjMdD0D-cas]
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.web.flow.SendTicketGrantingTicketAction] - Action
> 'SendTicketGrantingTicketAction' completed execution; result is 'success'
> 2009-01-20 15:48:19,108 DEBUG
> [org.jasig.cas.web.flow.GenerateServiceTicketAction] - Action
> 'GenerateServiceTicketAction' beginning execution
> 2009-01-20 15:48:19,109 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to
> retrieve ticket
> [TGT-1-tGfRQa0WAeN3Z5cODTaVMVfmPnex2oxBdKp7wWTErhWO0tpGje-cas]
> 2009-01-20 15:48:19,109 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket
> [TGT-1-tGfRQa0WAeN3Z5cODTaVMVfmPnex2oxBdKp7wWTErhWO0tpGje-cas] found in
> registry.
> 2009-01-20 15:48:19,114 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Added ticket
> [ST-1-krPbvTmY4e27fANfAsRP-cas] to registry.
> 2009-01-20 15:48:19,114 INFO
> [org.jasig.cas.CentralAuthenticationServiceImpl] - Granted service ticket
> [ST-1-krPbvTmY4e27fANfAsRP-cas] for service [
> http://dvorak.recia.fr/PRONOTEsso/] for user [F08001pi]
> 2009-01-20 15:48:19,115 DEBUG
> [org.jasig.cas.web.flow.GenerateServiceTicketAction] - Action
> 'GenerateServiceTicketAction' completed execution; result is 'success'
> 2009-01-20 15:48:19,181 DEBUG
> [org.jasig.cas.web.support.SamlArgumentExtractor] - Extractor generated
> service for: http://dvorak.recia.fr/PRONOTEsso/
> 2009-01-20 <http://dvorak.recia.fr/PRONOTEsso/2009-01-20> 15:48:19,182
> DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to
> retrieve ticket [ST-1-krPbvTmY4e27fANfAsRP-cas]
> 2009-01-20 15:48:19,182 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket
> [ST-1-krPbvTmY4e27fANfAsRP-cas] found in registry.
> 2009-01-20 15:48:19,183 DEBUG
> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket
> [ST-1-krPbvTmY4e27fANfAsRP-cas] from registry
> 2009-01-20 15:48:19,349 WARN [org.opensaml.XML] - Unable to turn off data
> normalization in parser, supersignatures may fail with Xerces-J:
> javax.xml.parsers.ParserConfigurationException: jaxp_feature_not_supported:
> Feature "http://apache.org/xml/features/validation/schema/normalized-value"
> is not supported.
> _______________________________________________
> Yale CAS mailing list
> cas at tp.its.yale.edu
> http://tp.its.yale.edu/mailman/listinfo/cas
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://tp.its.yale.edu/pipermail/cas/attachments/20090120/3a698535/attachment-0001.html

More information about the cas mailing list