CAS 5.3.7 Issue Pac4J OIDC + SAML2 Delegation

kyra1510

unread,

Feb 6, 2019, 2:56:47 AM2/6/19

to CAS Community

Hy all,

I apologize for my French English.

I have a problem when I upgrade my CAS 5.2.x to CAS 5.3.7 with the SAML delegation.

My Cas 5.3.7 is configure to use the OpenIdConnect authentication but it is possible to delegate the authentication to an IDP SAML2.

I have no problem with the delegation in CAS 5.2.x

When I use the OIDC authentication without delegation, the workflow is correct.

Workflow:

1 The user enter its password and login in the authentication page

2 The user is redirect to a consent page

3 When click on the button "allow", an authorization code is returned

But when I use the SAML2 delegation, I am not redirect to the consent page:

1 The user click on the button which redirect to the correct IDP

2 The user logged on the IDP SAML

3 After the user is returned to my CAS 5.3.7 and arrived on the page service?ticket=ST-xxxxxxxxxxxxxxxxxxxxxxxxxxxx and I have a code 302

I found this issue in the github which seems to correspond to my problem https://github.com/apereo/cas/pull/3664.

It describe the same issue in CAS 5.3.x in the SAML2 protocol before the bug was fixed. It didn't concern the delegation.

Could it be this problem is related to my issue?

Thanks for any help.

Kyra

Andy Ng

unread,

Feb 6, 2019, 10:01:35 PM2/6/19

to CAS Community

Hi Kyra,

After reading your problem and if I am not mistaken, I think your problem is mostly not related to https://github.com/apereo/cas/pull/3664 (I will reference it as #3664 ), hence studying the fix from #3664 most likely won't help you.

In #3664, the problem occurs when using SAML 2 authentication with attribute consent, and no additional delegation is involved.

In your case, the problem occurs when using OIDC authentication with OAuth consent, and there is SAML 2 delegation used.

As you can see from the color, the triggers for the above 2 issues are very different, so looking at #3664 are likely not going to give your the fix you need.

As for how to find your fix: OIDC authentication have a big revamp from 5.2.x to 5.3.x especially how the flow works, so I think you should actually look at what changed in OIDC authentication, that is more likely to help you find the fix.

One more thing, if you can also provide the debug log to the group, that might also help finding out the issue.

And unfortunately I don't have an SAML 2 delegation setup on my PC, so I can help debug your problem. Need to see if other in this group can help you.

- Andy

Message has been deleted

kyra1510

unread,

Feb 7, 2019, 3:52:02 AM2/7/19

to CAS Community

Hi Andy,

Thanks for looking my problem.

I'm not sure the problem is the OIDC authentication protocol.

Here are my tomcat logs (I anonymise my logs):

The IDP OIDC is the CAS 5.3.7 OIDC and the IDP SAML2 is the IDP where I delegate the authentication

LOG tomcat about the authentication OIDC without delegation SAML2

[07/Feb/2019:09:02:44 +0100] ip GET /oidc/authorize?response_type=code&client_id=clientId&redirect_uri=service&sco

pe=&state=af0ifjsldkj&acr_values=test HTTP/1.1 ?response_type=code&client_id=clientId&redirect_uri=service=&state=af0ifjsldkj&acr_values=test 302 5 451

[07/Feb/2019:09:02:48 +0100] ip GET /login?service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_name%3DCasOAuthClien

t%26client_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode HTTP/1.1 ?service=https

%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_name%3DCasOAuthClient%26client_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode 200 12090 2211

[07/Feb/2019:09:17:51 +0100] ip POST /login?service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode%26client_name%3DCasOAuthClient HTTP/1.1 ?service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode%26client_name%3DCasOAuthClient 302 - 427

[07/Feb/2019:09:17:53 +0100] ip GET /p3/serviceValidate?ticket=ST-1-xxxxxxxxxxidp-oidc.fr&service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode%26client_name%3DCasOAuthClient HTTP/1.1 ?ticket=ST-1-xxxxxxxxxxidp-oidc.fr&service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode%26client_name%3DCasOAuthClient 200 960 117

[07/Feb/2019:09:17:53 +0100] ip GET /oauth2.0/callbackAuthorize?client_id=clientId&redirect_uri=service&acr_values=test&response_type=code&client_name=CasOAuthClient&ticket=ST-1-xxxxxxxxxxxAidp-oidc.fr HTTP/1.1 ?client_id=clientId&redirect_uri=service&acr_values=test&response_type=code&client_name=CasOAuthClient&ticket=ST-1-xxxxxxxxxxxxxxAidp-oidc.fr 302 - 345

[07/Feb/2019:09:17:54 +0100] 10.35.103.12 GET /oidc/authorize?response_type=code&client_id=clientId&redirect_uri=service&scope=&state=af0ifjsldkj&acr_values=test HTTP/1.1 ?response_type=code&client_id=clientId&redirect_uri=service&scope=&state=af0ifjsldkj&acr_values=test 200 2563 75

LOG tomcat about the authentication OIDC with delegation SAML2

[07/Feb/2019:09:25:17 +0100] ip GET /oidc/authorize?response_type=code&client_id=clientId&redirect_uri=service&sco

pe=&state=af0ifjsldkj&acr_values=test HTTP/1.1 ?response_type=code&client_id=clientId&redirect_uri=service=&state=af0ifjsldkj&acr_values=test 302 5 11

[07/Feb/2019:09:25:18 +0100] ip GET /login?service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_name%3DCasOAuthClien

t%26client_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode HTTP/1.1 ?service=https

%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_name%3DCasOAuthClient%26client_id%3DclientId%26redirect_uri%3Dservice%26acr_values%3Dtest%26response_type%3Dcode 200 8909 138

[07/Feb/2019:09:30:38 +0100] ip GET /clientredirect?client_name=IDP-SAML2&service=service HTTP/1.1 ?client_name=SAML2&service=service 302 - 393

[07/Feb/2019:09:32:27 +0100] ip POST /login?client_name=IDP-SAML HTTP/1.1 ?client_name=clientId 302 - 247

[07/Feb/2019:09:32:28 +0100] 10.35.103.12 GET service?ticket=ST-2-xxxxxxxxxxxxxxxxxxxxxxxxx HTTP/1.1 ?ticket=ST-2-xxxxxxxxxxxxxxxxxxxxxxidp-oidc 404 2343 128

I see that during the OIDC authentication without delegation SAML2 the p3/serviceValidate is called but not with the delegation SAML2.

I think the problem occured when the IDP-SAML2 send the response to the IDP-OIDC.

Thanks for your help

Kyra

kyra1510

unread,

Feb 7, 2019, 3:59:42 AM2/7/19

to CAS Community

When I wrote service, I mean myService (the redirect_uri). Sorry for the trouble

Le mercredi 6 février 2019 08:56:47 UTC+1, kyra1510 a écrit :

Andy Ng

unread,

Feb 7, 2019, 9:57:07 AM2/7/19

to CAS Community

Hi Kyra,

> I'm not sure the problem is the OIDC authentication protocol.

The problem could be in any component, so you will need to look into all of them. I suggest it might be OIDC only because of my suspection, I don't actually have solid reason to support myself......

As for the log, The tomcat debug log won't give you too much detail even for yourself, you need to enable CAS debug log.

You can see how to enable it here: https://apereo.github.io/cas/6.0.x/installation/Troubleshooting-Guide.html#review-logs

CAS Debug log will be formatted something like the following:

2018-07-28 24:12:25,879 DEBUG [org.apereo.cas.services.DefaultServiceRegistryExecutionPlan] - <Registering service registry [OAuth20Ser
viceRegistry] into the execution plan>
2018-07-28 24:12:25,836 DEBUG [org.apereo.cas.services.AbstractServicesManager] - <Registering service registry [OAuth20ServiceRegistry
] into the execution planorg.apereo.cas.services.ChainingServiceRegistry@7a9f1582]>

........

So there will be more information for you to examine.

-Andy

kyra1510

unread,

Feb 8, 2019, 5:42:24 AM2/8/19

to CAS Community

Hi Andy,

Here are my cas.log about OIDC + delegation SAML2:

2019-02-08 09:36:20,832 DEBUG [org.apereo.cas.oidc.web.OidcCasClientRedirectActionBuilder] - <Final redirect action is [#RedirectAction# | type: REDIRECT | location: oidc.fr/login?service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_id%3Dservice.clientId%26redirect_uri%3Dservice.redirect_uri%26acr_values%3Dtest%26response_type%3Dcode%26client_name%3DCasOAuthClient | content: null |]>

2019-02-08 09:36:21,167 INFO [org.apereo.cas.web.flow.login.InitialFlowSetupAction] - <Setting path for cookies for warn cookie generator to: [/] >

2019-02-08 09:36:21,263 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Client Access Granted,client=IDP-SAML2,registeredService=service.clientId:^service.redirect_uri]

ACTION: DELEGATED_CLIENT_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 09:36:21 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 09:36:21,263 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Client Access Granted,client=IDP-SAML2,registeredService=serviceName:^service.redirect_uri]

ACTION: DELEGATED_CLIENT_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 09:36:21 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 09:36:21,292 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [event=success,timestamp=Fri Feb 08 09:36:21 CET 2019,source=RankedAuthenticationProviderWebflowEventResolver]

ACTION: AUTHENTICATION_EVENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 09:36:21 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 09:36:21,292 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [event=success,timestamp=Fri Feb 08 09:36:21 CET 2019,source=RankedAuthenticationProviderWebflowEventResolver]

ACTION: AUTHENTICATION_EVENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 09:36:21 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

2019-02-08 09:46:13,526 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Storing delegated authentication request ticket [TST-********************] for service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] with properties [{theme=, locale=, method=, service=AbstractWebApplicationService(id=service.redirect_uri, originalUrl=redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})}]>

2019-02-08 09:46:13,955 DEBUG [org.apereo.cas.web.DelegatedClientNavigationController] - <Redirecting client [IDP-SAML2] to [https://idp-SAML2/cas/idp/profile/SAML2/Redirect/SSO?SAMLRequest=fVJL****************&RelayState=TST-****************&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%23rsa-sha256&Signature=JfBh************.....] based on identifier [TST-*************************************]>

2019-02-08 09:46:13,966 DEBUG [org.apereo.cas.web.pac4j.SessionStoreCookieGenerator] - <Added cookie with name [PAC4JDELSESSION] and value [eyJ****Zw==.Elyf************]>

2019-02-08 09:53:06,842 DEBUG [org.apereo.cas.web.pac4j.SessionStoreCookieGenerator] - <Removed cookie with name [PAC4JDELSESSION]>

2019-02-08 09:53:06,842 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Client identifier could not found as part of the request parameters. Looking at relay-state for the SAML2 client>

I have an error at this moment because apereo set parameter to the samlRelayState and I think pac4J looked for RelayState so I modified the name but it is possible that is the opposite

2019-02-08 09:53:06,842 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Located delegated client identifier for this request as [null]>

2019-02-08 09:53:06,843 ERROR [org.apereo.cas.web.DelegatedClientWebflowManager] - <Delegated client identifier cannot be located in the authentication request [oidc.fr/login?client_name=IDP-SAML2]>

After I had an exception

2019-02-08 09:53:06,846 ERROR [org.apereo.cas.web.flow.DelegatedClientAuthenticationAction] - <>

org.apereo.cas.services.UnauthorizedServiceException:

at org.apereo.cas.web.DelegatedClientWebflowManager.retrieveSessionTicketViaClientId(DelegatedClientWebflowManager.java:180) ~[classes/:5.3.7]

at org.apereo.cas.web.DelegatedClientWebflowManager.retrieve(DelegatedClientWebflowManager.java:153) ~[classes/:5.3.7]

When I change RelayState to samlRelayState

2019-02-08 10:16:45,303 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Client identifier could not found as part of the request parameters. Looking at relay-state for the SAML2 client>

2019-02-08 10:16:45,303 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Located delegated client identifier for this request as [null]>

2019-02-08 10:16:45,305 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Located delegated client identifier as [TST-**************************]>

2019-02-08 10:16:45,305 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Restoring requested service [AbstractWebApplicationService(id=service.redirect_uri,

originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] back in the authentication flow

>

2019-02-08 10:16:45,305 DEBUG [org.apereo.cas.web.DelegatedClientWebflowManager] - <Removing delegated client identifier [TST-***************************} from registry>

2019-02-08 10:16:45,306 DEBUG [org.apereo.cas.web.flow.DelegatedClientAuthenticationAction] - <Delegated authentication client is [#SAML2Client# | name: IDP-ENT-test-dev3 | callbackUrl: https://idp-oidc

.fr/login | urlResolver: org.pac4j.core.http.url.DefaultUrlResolver@1a8335ef | callbackUrlResolver: org.pac4j.core.http.callback.QueryParameterCallbackUrlResolver@48630fdc | ajax

RequestResolver: org.pac4j.core.http.ajax.DefaultAjaxRequestResolver@625a354d | redirectActionBuilder: org.pac4j.saml.redirect.SAML2RedirectActionBuilder@197fae8c | credentialsExtractor: org.pac4j.saml.cred

entials.extractor.SAML2CredentialsExtractor@1ad0dc01 | authenticator: org.pac4j.saml.credentials.authenticator.SAML2Authenticator@4a1d2d68 | profileCreator: org.pac4j.core.profile.creator.AuthenticatorProfi

leCreator@36aab35d | logoutActionBuilder: org.pac4j.saml.logout.SAML2LogoutActionBuilder@795e993b | authorizationGenerators: [] |] with service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})}

>

2019-02-08 10:16:45,307 DEBUG [org.apereo.cas.web.flow.DelegatedClientAuthenticationAction] - <Located registered service definition [OidcRegisteredService(super=OAuthRegisteredService(super=AbstractRegiste

redService(serviceId=^service.redirect_uri, name=service.clientId, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=***, descript

ion=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPo

licy@1, evaluationOrder=0, usernameAttributeProvider=PrincipalAttributeRegisteredServiceUsernameProvider(usernameAttribute=IDO), logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ChainingAttributeReleasePolicy(policies=[BaseOidcScopeAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[name, family_name, given_name, middle_name, nickname, preferred_username, profile, picture, website, gender, birthdate, zoneinfo, locale, updated_at], scopeName=profile)]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[mfa-duo], failureMode=NONE, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[]), clientSecret=secret, clientId=androidGarClient, bypassApprovalPrompt=false, generateRefreshToken=true, jsonFormat=true, supportedGrantTypes=[], supportedResponseTypes=[]), jwks=null, signIdToken=true, encryptIdToken=false, idTokenEncryptionAlg=null, idTokenEncryptionEncoding=null, sectorIdentifierUri=null, subjectType=public, dynamicallyRegistered=false, implicit=false, dynamicRegistrationDateTime=null, scopes=[profile])] matching [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,307 DEBUG [org.apereo.cas.web.flow.DelegatedClientAuthenticationAction] - <Located registered service definition [OidcRegisteredService(super=OAuthRegisteredService(super=AbstractRegisteredService(serviceId=^service.redirect_uri, name=service.clientId, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=*****, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, evaluationOrder=0, usernameAttributeProvider=PrincipalAttributeRegisteredServiceUsernameProvider(usernameAttribute=*****), logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ChainingAttributeReleasePolicy(policies=[BaseOidcScopeAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[name, family_name, given_name, middle_name, nickname, preferred_username, profile, picture, website, gender, birthdate, zoneinfo, locale, updated_at], scopeName=profile)]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[mfa-duo], failureMode=NONE, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[]), clientSecret=service.secret, clientId=service.clientId, bypassApprovalPrompt=false, generateRefreshToken=true, jsonFormat=true, supportedGrantTypes=[], supportedResponseTypes=[]), jwks=null, signIdToken=true, encryptIdToken=false, idTokenEncryptionAlg=null, idTokenEncryptionEncoding=null, sectorIdentifierUri=null, subjectType=public, dynamicallyRegistered=false, implicit=false, dynamicRegistrationDateTime=null, scopes=[profile])] matching [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,307 WARN [org.apereo.cas.services.DefaultRegisteredServiceDelegatedAuthenticationPolicy] - <Registered service [service.clientName] does not define any authorized/supported delegated authentication providers. It is STRONGLY recommended that you authorize and assign providers to the service definition. While just a warning for now, this behavior will be enforced by CAS in future versions.>

2019-02-08 10:16:45,307 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Client Access Granted,client=IDPSAML2,registeredService=service.clientName:^service.redirect_uri]

ACTION: DELEGATED_CLIENT_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 10:16:45,307 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Client Access Granted,client=IDP-SAML2,registeredService=service.clientName:^service.redirect_uri]

ACTION: DELEGATED_CLIENT_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

2019-02-08 10:16:45,308 DEBUG [org.apereo.cas.web.flow.DelegatedClientAuthenticationAction] - <Delegated authentication policy for [OidcRegisteredService(super=OAuthRegisteredService(super=AbstractRegisteredService(serviceId=^service.redirect_uri, name=service.clientName, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=1003, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, evaluationOrder=0, usernameAttributeProvider=PrincipalAttributeRegisteredServiceUsernameProvider(usernameAttribute=*******), logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ChainingAttributeReleasePolicy(policies=[BaseOidcScopeAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[name, family_name, given_name, middle_name, nickname, preferred_username, profile, picture, website, gender, birthdate, zoneinfo, locale, updated_at], scopeName=profile)]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[mfa-duo], failureMode=NONE, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[]), clientSecret=service.secret, clientId=service.clientId, bypassApprovalPrompt=false, generateRefreshToken=true, jsonFormat=true, supportedGrantTypes=[], supportedResponseTypes=[]), jwks=null, signIdToken=true, encryptIdToken=false, idTokenEncryptionAlg=null, idTokenEncryptionEncoding=null, sectorIdentifierUri=null, subjectType=public, dynamicallyRegistered=false, implicit=false, dynamicRegistrationDateTime=null, scopes=[profile])] allows for using client [#SAML2Client# | name: IDP-SAML2 | callbackUrl: https://idp-oidc.fr/login | urlResolver: org.pac4j.core.http.url.DefaultUrlResolver@1a8335ef | callbackUrlResolver: org.pac4j.core.http.callback.QueryParameterCallbackUrlResolver@48630fdc | ajaxRequestResolver: org.pac4j.core.http.ajax.DefaultAjaxRequestResolver@625a354d | redirectActionBuilder: org.pac4j.saml.redirect.SAML2RedirectActionBuilder@197fae8c | credentialsExtractor: org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor@1ad0dc01 | authenticator: org.pac4j.saml.credentials.authenticator.SAML2Authenticator@4a1d2d68 | profileCreator: org.pac4j.core.profile.creator.AuthenticatorProfileCreator@36aab35d | logoutActionBuilder: org.pac4j.saml.logout.SAML2LogoutActionBuilder@795e993b | authorizationGenerators: [] |]>

2019-02-08 10:16:45,488 DEBUG [org.apereo.cas.web.flow.DelegatedClientAuthenticationAction] - <Retrieved credentials from client as [SAML2Credentials{nameId=SAMLNameID{format='urn:oasis:names:tc:SAML:2.0:nameid-format:transient', nameQualifier='null', spNameQualifier='null', spProviderId='null', value='userLogged(pseudo)'}, sessionIndex='null', attributes=[SAMLAttribute{friendlyName='samlAuthenticationStatementAuthMethod', name='samlAuthenticationStatementAuthMethod', nameFormat='null', attributeValues=[urn:oasis:names:tc:SAML:1.0:am:password]}, SAMLAttribute{friendlyName='isFromNewLogin', name='isFromNewLogin', nameFormat='null', attributeValues=[false]}, SAMLAttribute{friendlyName='authenticationDate', name='authenticationDate', nameFormat='null', attributeValues=[2019-02-08T10:16:44.509+01:00[Europe/Paris]]}, SAMLAttribute{friendlyName='authenticationMethod', name='authenticationMethod', nameFormat='null', attributeValues=[FileAuthenticationHandler]}, SAMLAttribute{friendlyName='successfulAuthenticationHandlers', name='successfulAuthenticationHandlers', nameFormat='null', attributeValues=[FileAuthenticationHandler]}, SAMLAttribute{friendlyName='longTermAuthenticationRequestTokenUsed', name='longTermAuthenticationRequestTokenUsed', nameFormat='null', attributeValues=[false]}], conditions=SAMLConditions{notBefore=2019-02-08T09:16:44.605Z, notOnOrAfter=2019-02-08T09:16:44.605Z}, issuerId='https://idp-SAML2', authnContexts=[urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified]}]>

2019-02-08 10:16:45,490 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [ServiceTicketRequestWebflowEventResolver]>

2019-02-08 10:16:45,491 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Located ticket-granting ticket [null] from the request context>

2019-02-08 10:16:45,491 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Located service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] from the request context>

2019-02-08 10:16:45,491 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Provided value for [renew] request parameter is [null]>

2019-02-08 10:16:45,491 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Request is not eligible to be issued service tickets just yet>

2019-02-08 10:16:45,492 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [InitialAuthenticationAttemptWebflowEventResolver]>

2019-02-08 10:16:45,524 DEBUG [org.apereo.cas.support.pac4j.authentication.handler.support.ClientAuthenticationHandler] - <Located client credentials as [ClientCredential(typedIdUsed=false, userProfile=#SAML2Profile# | id: userPseudo | attributes: {samlAuthenticationStatementAuthMethod=[urn:oasis:names:tc:SAML:1.0:am:password], isFromNewLogin=[false], authenticationDate=[2019-02-08T10:16:44.509+01:00[Europe/Paris]], authenticationMethod=[FileAuthenticationHandler], successfulAuthenticationHandlers=[FileAuthenticationHandler], notOnOrAfter=2019-02-08T09:16:44.605Z, longTermAuthenticationRequestTokenUsed=[false], notBefore=2019-02-08T09:16:44.605Z} | roles: [] | permissions: [] | isRemembered: false | clientName: IDP-SAML2 | linkedId: null |, credentials=SAML2Credentials{nameId=SAMLNameID{format='urn:oasis:names:tc:SAML:2.0:nameid-format:transient', nameQualifier='null', spNameQualifier='null', spProviderId='null', value='userPseudo'}, sessionIndex='null', attributes=[SAMLAttribute{friendlyName='samlAuthenticationStatementAuthMethod', name='samlAuthenticationStatementAuthMethod', nameFormat='null', attributeValues=[urn:oasis:names:tc:SAML:1.0:am:password]}, SAMLAttribute{friendlyName='isFromNewLogin', name='isFromNewLogin', nameFormat='null', attributeValues=[false]}, SAMLAttribute{friendlyName='authenticationDate', name='authenticationDate', nameFormat='null', attributeValues=[2019-02-08T10:16:44.509+01:00[Europe/Paris]]}, SAMLAttribute{friendlyName='authenticationMethod', name='authenticationMethod', nameFormat='null', attributeValues=[FileAuthenticationHandler]}, SAMLAttribute{friendlyName='successfulAuthenticationHandlers', name='successfulAuthenticationHandlers', nameFormat='null', attributeValues=[FileAuthenticationHandler]}, SAMLAttribute{friendlyName='longTermAuthenticationRequestTokenUsed', name='longTermAuthenticationRequestTokenUsed', nameFormat='null', attributeValues=[false]}], conditions=SAMLConditions{notBefore=2019-02-08T09:16:44.605Z, notOnOrAfter=2019-02-08T09:16:44.605Z}, issuerId='https://IDP-SAML2/cas/idp', authnContexts=[urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified]}, clientName=IDP-SAML2.clientName)]>

2019-02-08 10:16:45,524 DEBUG [org.apereo.cas.support.pac4j.authentication.handler.support.ClientAuthenticationHandler] - <Client name: [IDP-SAML2.clientName]>

2019-02-08 10:16:45,525 DEBUG [org.apereo.cas.support.pac4j.authentication.handler.support.ClientAuthenticationHandler] - <Delegated client is: [#SAML2Client# | name: IDP-SAML2.clientName | callbackUrl: https://idp-oidc.fr/login | urlResolver: org.pac4j.core.http.url.DefaultUrlResolver@1a8335ef | callbackUrlResolver: org.pac4j.core.http.callback.QueryParameterCallbackUrlResolver@48630fdc | ajaxRequestResolver: org.pac4j.core.http.ajax.DefaultAjaxRequestResolver@625a354d | redirectActionBuilder: org.pac4j.saml.redirect.SAML2RedirectActionBuilder@197fae8c | credentialsExtractor: org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor@1ad0dc01 | authenticator: org.pac4j.saml.credentials.authenticator.SAML2Authenticator@4a1d2d68 | profileCreator: org.pac4j.core.profile.creator.AuthenticatorProfileCreator@36aab35d | logoutActionBuilder: org.pac4j.saml.logout.SAML2LogoutActionBuilder@795e993b | authorizationGenerators: [] |]>

2019-02-08 10:16:45,525 DEBUG [org.apereo.cas.support.pac4j.authentication.handler.support.ClientAuthenticationHandler] - <Final user profile is: [#SAML2Profile# | id: userPseudo | attributes: {samlAuthenticationStatementAuthMethod=[urn:oasis:names:tc:SAML:1.0:am:password], isFromNewLogin=[false], authenticationDate=[2019-02-08T10:16:44.509+01:00[Europe/Paris]], authenticationMethod=[FileAuthenticationHandler], successfulAuthenticationHandlers=[FileAuthenticationHandler], notOnOrAfter=2019-02-08T09:16:44.605Z, longTermAuthenticationRequestTokenUsed=[false], notBefore=2019-02-08T09:16:44.605Z} | roles: [] | permissions: [] | isRemembered: false | clientName: IDP-SAML2.clientName | linkedId: null |]>

2019-02-08 10:16:45,546 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: Supplied credentials: [ClientCredential(typedIdUsed=false, userProfile=#SAML2Profile# | id: userPseudo | attributes: {samlAuthenticationStatementAuthMethod=[urn:oasis:names:tc:SAML:1.0:am:password], isFromNewLogin=[false], authenticationDate=[2019-02-08T10:16:44.509+01:00[Europe/Paris]], authenticationMethod=[FileAuthenticationHandler], successfulAuthenticationHandlers=[FileAuthenticationHandler], notOnOrAfter=2019-02-08T09:16:44.605Z, longTermAuthenticationRequestTokenUsed=[false], notBefore=2019-02-08T09:16:44.605Z} | roles: [] | permissions: [] | isRemembered: false | clientName: service.clientName | linkedId: null |, credentials=SAML2Credentials{nameId=SAMLNameID{format='urn:oasis:names:tc:SAML:2.0:nameid-format:transient', nameQualifier='null', spNameQualifier='null', spProviderId='null', value='userPseudo'}, sessionIndex='null', attributes=[SAMLAttribute{friendlyName='samlAuthenticationStatementAuthMethod', name='samlAuthenticationStatementAuthMethod', nameFormat='null', attributeValues=[urn:oasis:names:tc:SAML:1.0:am:password]}, SAMLAttribute{friendlyName='isFromNewLogin', name='isFromNewLogin', nameFormat='null', attributeValues=[false]}, SAMLAttribute{friendlyName='authenticationDate', name='authenticationDate', nameFormat='null', attributeValues=[2019-02-08T10:16:44.509+01:00[Europe/Paris]]}, SAMLAttribute{friendlyName='authenticationMethod', name='authenticationMethod', nameFormat='null', attributeValues=[FileAuthenticationHandler]}, SAMLAttribute{friendlyName='successfulAuthenticationHandlers', name='successfulAuthenticationHandlers', nameFormat='null', attributeValues=[FileAuthenticationHandler]}, SAMLAttribute{friendlyName='longTermAuthenticationRequestTokenUsed', name='longTermAuthenticationRequestTokenUsed', nameFormat='null', attributeValues=[false]}], conditions=SAMLConditions{notBefore=2019-02-08T09:16:44.605Z, notOnOrAfter=2019-02-08T09:16:44.605Z}, issuerId='https://IDP-SAML2/cas/idp', authnContexts=[urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified]}, clientName=IDP-SAML2.clientName)]

ACTION: AUTHENTICATION_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 10:16:45,550 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Locating service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] in service registry to determine authentication policy>

2019-02-08 10:16:45,550 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Locating authentication event in the request context...>

2019-02-08 10:16:45,550 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Enforcing access strategy policies for registered service [OidcRegisteredService(super=OAuthRegisteredService(super=AbstractRegisteredService(serviceId=^service.redirect_uri, name=service.clientName, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=1003, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, evaluationOrder=0, usernameAttributeProvider=PrincipalAttributeRegisteredServiceUsernameProvider(usernameAttribute=*****), logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ChainingAttributeReleasePolicy(policies=[BaseOidcScopeAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[name, family_name, given_name, middle_name, nickname, preferred_username, profile, picture, website, gender, birthdate, zoneinfo, locale, updated_at], scopeName=profile)]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[mfa-duo], failureMode=NONE, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[]), clientSecret=service.secret, clientId=service.clientId, bypassApprovalPrompt=false, generateRefreshToken=true, jsonFormat=true, supportedGrantTypes=[], supportedResponseTypes=[]), jwks=null, signIdToken=true, encryptIdToken=false, idTokenEncryptionAlg=null, idTokenEncryptionEncoding=null, sectorIdentifierUri=null, subjectType=public, dynamicallyRegistered=false, implicit=false, dynamicRegistrationDateTime=null, scopes=[profile])] and principal [SimplePrincipal(id=userPseudo, attributes={samlAuthenticationStatementAuthMethod=[urn:oasis:names:tc:SAML:1.0:am:password], isFromNewLogin=[false], authenticationDate=[2019-02-08T10:16:44.509+01:00[Europe/Paris]], authenticationMethod=[FileAuthenticationHandler], successfulAuthenticationHandlers=[FileAuthenticationHandler], notOnOrAfter=2019-02-08T09:16:44.605Z, longTermAuthenticationRequestTokenUsed=[false], notBefore=2019-02-08T09:16:44.605Z})]>

2019-02-08 10:16:45,557 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: [result=Service Access Granted,service=service.redirect_uri,principal=SimplePrincipal(id=userPseudo, attributes={samlAuthenticationStatementAuthMethod=[urn:oasis:names:tc:SAML:1.0:am:password], isFromNewLogin=[false], authenticationDate=[2019-02-08T10:16:44.509+01:00[Europe/Paris]], authenticationMethod=[FileAuthenticationHandler], successfulAuthenticationHandlers=[FileAuthenticationHandler], notOnOrAfter=2019-02-08T09:16:44.605Z, longTermAuthenticationRequestTokenUsed=[false], notBefore=2019-02-08T09:16:44.605Z}),requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 10:16:45,558 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Attempting to resolve candidate authentication events for service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,566 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [AdaptiveMultifactorAuthenticationPolicyEventResolver]>

2019-02-08 10:16:45,568 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [AdaptiveMultifactorAuthenticationPolicyEventResolver]>

2019-02-08 10:16:45,568 DEBUG [org.apereo.cas.web.flow.resolver.impl.mfa.adaptive.AdaptiveMultifactorAuthenticationPolicyEventResolver] - <Adaptive authentication is not configured to require multifactor authentication>

2019-02-08 10:16:45,592 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [RequestParameterMultifactorAuthenticationPolicyEventResolver]>

2019-02-08 10:16:45,594 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [RequestParameterMultifactorAuthenticationPolicyEventResolver]>

2019-02-08 10:16:45,595 DEBUG [org.apereo.cas.web.flow.resolver.impl.mfa.request.RequestParameterMultifactorAuthenticationPolicyEventResolver] - <No value could be found for request parameter [authn_method]>

2019-02-08 10:16:45,601 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [RequestHeaderMultifactorAuthenticationPolicyEventResolver]>

2019-02-08 10:16:45,602 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [RequestHeaderMultifactorAuthenticationPolicyEventResolver]>

2019-02-08 10:16:45,685 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [OidcAuthenticationContextWebflowEventResolver]>

2019-02-08 10:16:45,686 DEBUG [org.apereo.cas.oidc.web.flow.OidcAuthenticationContextWebflowEventResolver] - <No ACR provided in the authentication request>

2019-02-08 10:16:45,686 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <No candidate authentication events were resolved for service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,686 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Resolved single event [success] via [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] for this context>

2019-02-08 10:16:45,687 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Finalizing authentication transactions and issuing ticket-granting ticket>

2019-02-08 10:16:45,695 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Finalizing authentication event...>

2019-02-08 10:16:45,696 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Creating ticket-granting ticket, potentially based on [null]>

2019-02-08 10:16:45,696 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Attempting to issue a new ticket-granting ticket...>

2019-02-08 10:16:45,705 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: [result=Service Access Granted,service=service.redirect_uri,principal=SimplePrincipal(id=userPseudo, attributes={samlAuthenticationStatementAuthMethod=[urn:

oasis:names:tc:SAML:1.0:am:password], isFromNewLogin=[false], authenticationDate=[2019-02-08T10:16:44.509+01:00[Europe/Paris]], authenticationMethod=[FileAuthenticationHandler], successfulAuthenticationHandle

rs=[FileAuthenticationHandler], notOnOrAfter=[2019-02-08T09:16:44.605Z], longTermAuthenticationRequestTokenUsed=[false], notBefore=[2019-02-08T09:16:44.605Z]}),requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 10:16:45,731 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: TGT-1-*******************************************************************************************st-oidc.fr

ACTION: TICKET_GRANTING_TICKET_CREATED

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 10:16:45,731 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: TGT-1-*******************************************************************************************st-oidc.fr

ACTION: TICKET_GRANTING_TICKET_CREATED

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

2019-02-08 10:16:45,732 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Calculating authentication warning messages...>

2019-02-08 10:16:45,733 DEBUG [org.apereo.cas.web.flow.DefaultSingleSignOnParticipationStrategy] - <Located [^service.redirect_uri] in registry. Service access to participate in SSO is set to [true]>

2019-02-08 10:16:45,734 DEBUG [org.apereo.cas.web.flow.login.SendTicketGrantingTicketAction] - <Setting ticket-granting cookie for current session linked to [TGT-1-*******************************************************************************************st-oidc.fr].>

2019-02-08 10:16:45,737 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Service asking for service ticket is [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,737 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Ticket-granting ticket found in the context is [TGT-1-*******************************************************************************************st-oidc.fr]>

2019-02-08 10:16:45,745 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Registered service asking for service ticket is [OidcRegisteredService(super=OAuthRegisteredService(super=AbstractRegisteredService(serviceId=^service.redirect_uri, name=service.clientName, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=****, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, evaluationOrder=0, usernameAttributeProvider=PrincipalAttributeRegisteredServiceUsernameProvider(usernameAttribute=****), logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ChainingAttributeReleasePolicy(policies=[BaseOidcScopeAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[name, family_name, given_name, middle_name, nickname, preferred_username, profile, picture, website, gender, birthdate, zoneinfo, locale, updated_at], scopeName=profile)]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[mfa-duo], failureMode=NONE, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[]), clientSecret=service.clientSecret, clientId=service.clientId, bypassApprovalPrompt=false, generateRefreshToken=true, jsonFormat=true, supportedGrantTypes=[], supportedResponseTypes=[]), jwks=null, signIdToken=true, encryptIdToken=false, idTokenEncryptionAlg=null, idTokenEncryptionEncoding=null, sectorIdentifierUri=null, subjectType=public, dynamicallyRegistered=false, implicit=false, dynamicRegistrationDateTime=null, scopes=[profile])]>

2019-02-08 10:16:45,746 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Built the final authentication result [DefaultAuthenticationResult(credentialProvided=true, authentication=org.apereo.cas.authentication.DefaultAuthentication@8e4e9ee1, service=AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={}))] to grant service ticket to [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,750 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: [result=Service Access Granted,service=service.redirect_uri,requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: idp

SERVER IP ADDRESS: idp

=============================================================

>

2019-02-08 10:16:45,775 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: ST-1-****idp-oidc.fr for service.redirect_uri

ACTION: SERVICE_TICKET_CREATED

APPLICATION: CAS

WHEN: Fri Feb 08 10:16:45 CET 2019

CLIENT IP ADDRESS: idp

SERVER IP ADDRESS: idp

=============================================================

>

2019-02-08 10:16:45,780 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Granted service ticket [ST-1-****idp-oidc.fr] and added it to the request scope>

2019-02-08 10:16:45,781 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})] from the context>

2019-02-08 10:16:45,781 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located authentication [org.apereo.cas.authentication.DefaultAuthentication@5ecac821] from the context>

2019-02-08 10:16:45,782 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service response builder [org.apereo.cas.authentication.principal.WebApplicationServiceResponseBuilder@f5c1f973] for [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,787 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Built response [org.apereo.cas.authentication.principal.DefaultResponse@19db421] for [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 10:16:45,787 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Signaling flow to redirect to service [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})] via event [redirect]>

I don't know when the error occured. I will publish the logs about OIDC authentication later

Thanks for your help,

Kyra

Le mercredi 6 février 2019 08:56:47 UTC+1, kyra1510 a écrit :

kyra1510

unread,

Feb 8, 2019, 6:41:41 AM2/8/19

to CAS Community

Here my logs for normal OIDC flow:

2019-02-08 11:44:30,863 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [RankedAuthenticationProviderWebflowEventResolver]>

2019-02-08 11:44:30,863 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Resolved single event [success] via [org.apereo.cas.web.flow.resolver.impl.RankedAuthenticationProviderWebflowEventResolver] for this context>

2019-02-08 11:44:30,864 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [event=success,timestamp=Fri Feb 08 11:44:30 CET 2019,source=RankedAuthenticationProviderWebflowEventResolver]

ACTION: AUTHENTICATION_EVENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:44:30 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:44:30,864 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [event=success,timestamp=Fri Feb 08 11:44:30 CET 2019,source=RankedAuthenticationProviderWebflowEventResolver]

ACTION: AUTHENTICATION_EVENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:44:30 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:44:30,867 DEBUG [org.apereo.cas.web.flow.login.InitializeLoginAction] - <Initialized login sequence>

2019-02-08 11:44:30,982 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages_fr_FR] - neither plain properties nor XML>

2019-02-08 11:44:30,983 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:messages_fr_FR] - neither plain properties nor XML>

2019-02-08 11:44:30,984 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages_fr] - neither plain properties nor XML>

2019-02-08 11:44:30,984 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <Loading properties [messages_fr.properties] with encoding 'UTF-8'>

2019-02-08 11:46:26,280 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [ServiceTicketRequestWebflowEventResolver]>

2019-02-08 11:46:26,280 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Located ticket-granting ticket [null] from the request context>

2019-02-08 11:46:26,281 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Located service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://id

p-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasO

AuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] from the request context>

2019-02-08 11:46:26,281 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Located service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientName&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://id

oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientID&redirect_uri=service.redirect_uri&response_type=code&client_name=CasO

AuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] from the request context>

2019-02-08 11:46:26,281 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Provided value for [renew] request parameter is [null]>

2019-02-08 11:46:26,281 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Request is not eligible to be issued service tickets just yet>

2019-02-08 11:46:26,282 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [InitialAuthenticationAttemptWebflowEventResolver]>

2019-02-08 11:46:26,319 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Examining credential [UsernamePasswordCredential(username=userPseudo)] eligibility for authentication handler [AcceptUsersAuthenticationHandler]>

2019-02-08 11:46:26,319 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential [UsernamePasswordCredential(username=userPseudo)] eligibility is [AcceptUsersAuthenticationHandler] for authentication handler [true]>

2019-02-08 11:46:26,322 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Transforming credential username via [org.apereo.cas.util.transforms.ChainingPrincipalNameTransformer]>

2019-02-08 11:46:26,322 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Attempting to encode credential password via [org.springframework.security.crypto.password.NoOpPasswordEncoder] for [userPseudo]>

2019-02-08 11:46:26,322 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Attempting authentication internally for transformed credential [UsernamePasswordCredential(username=userPseudo)]>

2019-02-08 11:46:26,350 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: Supplied credentials: [UsernamePasswordCredential(username=userPseudo)]

ACTION: AUTHENTICATION_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:26,350 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: Supplied credentials: [UsernamePasswordCredential(username=userPseudo)]

ACTION: AUTHENTICATION_SUCCESS

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:26,355 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Locating service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] in service registry to determine authentication policy>

2019-02-08 11:46:26,355 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Locating authentication event in the request context...>

2019-02-08 11:46:26,355 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Enforcing access strategy policies for registered service [AbstractRegisteredService(serviceId=https://idp-oidc.fr/oauth2.0/callbackAuthorize.*, name=RegexRegisteredService, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=*******, description=OAuth Authentication Callback Request URL, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, evaluationOrder=0, usernameAttributeProvider=org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider@87297e2, logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=true, authorizedToReleaseAuthenticationAttributes=false, principalIdAttribute=null), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[], failureMode=NOT_SET, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[])] and principal [SimplePrincipal(id=userPseudo, attributes={})]>

2019-02-08 11:46:26,363 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: [result=Service Access Granted,service=https://idp-oidc..,principal=SimplePrincipal(id=userPseudo, attributes={}),requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:26,529 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [OidcAuthenticationContextWebflowEventResolver]>

2019-02-08 11:46:26,529 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Attempting to resolve authentication event using resolver [OidcAuthenticationContextWebflowEventResolver]>

2019-02-08 11:46:26,532 DEBUG [org.apereo.cas.oidc.web.flow.OidcAuthenticationContextWebflowEventResolver] - <No ACR provided in the authentication request>

2019-02-08 11:46:26,533 DEBUG [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] - <No candidate authentication events were resolved for service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 11:46:26,533 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Resolved single event [success] via [org.apereo.cas.web.flow.resolver.impl.InitialAuthenticationAttemptWebflowEventResolver] for this context>

2019-02-08 11:46:26,533 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Finalizing authentication transactions and issuing ticket-granting ticket>

2019-02-08 11:46:26,547 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Finalizing authentication event...>

2019-02-08 11:46:26,548 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Creating ticket-granting ticket, potentially based on [null]>

2019-02-08 11:46:26,548 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Attempting to issue a new ticket-granting ticket...>

2019-02-08 11:46:26,558 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: [result=Service Access Granted,service=https://idp-oidc...,principal=SimplePrincipal(id=userPseudo, attributes={}),requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:26,594 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: TGT-1-*******************************************************************************************st-oidc.fr

ACTION: TICKET_GRANTING_TICKET_CREATED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:26,595 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Calculating authentication warning messages...>

2019-02-08 11:46:26,597 DEBUG [org.apereo.cas.web.flow.DefaultSingleSignOnParticipationStrategy] - <Located [https://idp-oidc.fr/oauth2.0/callbackAuthorize.*] in registry. Service access to participate in SSO is set to [true]>

2019-02-08 11:46:26,597 DEBUG [org.apereo.cas.web.flow.login.SendTicketGrantingTicketAction] - <Setting ticket-granting cookie for current session linked to [TGT-1-*******************************************************************************************st-oidc.fr].>

2019-02-08 11:46:26,609 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Service asking for service ticket is [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 11:46:26,609 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Ticket-granting ticket found in the context is [TGT-1-*******************************************************************************************st-oidc.fr]>

2019-02-08 11:46:26,621 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Registered service asking for service ticket is [OidcRegisteredService(super=OAuthRegisteredService(super=AbstractRegisteredService(serviceId=^service.redirect_uri, name=service.clientName, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=*****, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, evaluationOrder=0, usernameAttributeProvider=PrincipalAttributeRegisteredServiceUsernameProvider(usernameAttribute=*****), logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ChainingAttributeReleasePolicy(policies=[BaseOidcScopeAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[name, family_name, given_name, middle_name, nickname, preferred_username, profile, picture, website, gender, birthdate, zoneinfo, locale, updated_at], scopeName=profile)]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[mfa-duo], failureMode=NONE, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[]), clientSecret=service.secret, clientId=service.clientId, bypassApprovalPrompt=false, generateRefreshToken=true, jsonFormat=true, supportedGrantTypes=[], supportedResponseTypes=[]), jwks=null, signIdToken=true, encryptIdToken=false, idTokenEncryptionAlg=null, idTokenEncryptionEncoding=null, sectorIdentifierUri=null, subjectType=public, dynamicallyRegistered=false, implicit=false, dynamicRegistrationDateTime=null, scopes=[profile])]>

2019-02-08 11:46:26,622 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Built the final authentication result [DefaultAuthenticationResult(credentialProvided=true, authentication=org.apereo.cas.authentication.DefaultAuthentication@fb5a4f06, service=AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.cientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={}))] to grant service ticket to [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 11:46:26,625 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: [result=Service Access Granted,service=service.redirect_uri...,requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:26,660 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: ST-1-*****idp-oidc.fr for https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri...

ACTION: SERVICE_TICKET_CREATED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:26 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

2019-02-08 11:46:26,660 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Granted service ticket [ST-1-*****idp-oidc.fr] and added it to the request scope>

2019-02-08 11:46:26,661 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri%3A%2Foauthredirect&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})] from the context>

2019-02-08 11:46:26,661 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located authentication [org.apereo.cas.authentication.DefaultAuthentication@b488a386] from the context>

2019-02-08 11:46:26,662 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service ticket [ST-1-*****idp-oidc.fr] from the context>

2019-02-08 11:46:26,662 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service response builder [org.apereo.cas.authentication.principal.WebApplicationServiceResponseBuilder@2a31b369] for [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 11:46:26,702 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Built response [org.apereo.cas.authentication.principal.DefaultResponse@36e645e1] for [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 11:46:26,703 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Signaling flow to redirect to service [AbstractWebApplicationService(id=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, originalUrl=https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient, artifactId=null, principal=userPseudo, source=service, loggedOutAlready=false, format=XML, attributes={})] via event [redirect]>

2019-02-08 11:46:27,055 DEBUG [org.jasig.cas.client.validation.Cas30ServiceTicketValidator] - <Placing URL parameters in map.>

2019-02-08 11:46:27,055 DEBUG [org.jasig.cas.client.validation.Cas30ServiceTicketValidator] - <Calling template URL attribute map.>

2019-02-08 11:46:27,055 DEBUG [org.jasig.cas.client.validation.Cas30ServiceTicketValidator] - <Loading custom parameters from configuration.>

2019-02-08 11:46:27,056 DEBUG [org.jasig.cas.client.validation.Cas30ServiceTicketValidator] - <Constructing validation url: https://idp-oidc.fr/p3/serviceValidate?ticket=ST-1-***idp-oidc.fr&service=https%3A%2F%2Fidp-oidc.fr%2Foauth2.0%2FcallbackAuthorize%3Fclient_id%3Dservice.clientId%26redirect_uri%3Dservice.redirect_uri%26response_type%3Dcode%26client_name%3DCasOAuthClient>

2019-02-08 11:46:27,056 DEBUG [org.jasig.cas.client.validation.Cas30ServiceTicketValidator] - <Retrieving response from server.>

2019-02-08 11:46:27,227 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Service Access Granted,service=service.redirect_uri,principal=SimplePrincipal(id=userPseudo, attributes={}),requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:27 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

2019-02-08 11:46:27,241 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: userPseudo

WHAT: ST-****idp-oidc.fr

ACTION: SERVICE_TICKET_VALIDATED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:27 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:27,246 DEBUG [org.apereo.cas.web.AbstractServiceValidateController] - <Locating the primary authentication associated with this service request [AbstractWebApplicationService(id=service.redirect_uri, originalUrl=service.redirect_uri, artifactId=ST-1-*****idp-oidc.fr, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>

2019-02-08 11:46:27,246 DEBUG [org.apereo.cas.web.AbstractServiceValidateController] - <No particular authentication context is required for this request>

2019-02-08 11:46:27,246 DEBUG [org.apereo.cas.web.AbstractServiceValidateController] - <No service credentials specified, and/or the proxy handler [org.apereo.cas.ticket.proxy.support.Cas20ProxyHandler@3bf721e5] cannot handle credentials>

2019-02-08 11:46:27,246 DEBUG [org.apereo.cas.web.AbstractServiceValidateController] - <Successfully validated service ticket [ST-1-****idp-oidc.fr] for service [https://idp-oidc.fr/oauth2.0/callbackAuthorize?client_id=service.clientId&redirect_uri=service.redirect_uri&response_type=code&client_name=CasOAuthClient]>

2019-02-08 11:46:27,254 DEBUG [org.apereo.cas.web.view.Cas20ResponseView] - <Prepared CAS response output model with attribute names [[assertion, service, org.springframework.validation.BindingResult.assertion, org.springframework.validation.BindingResult.service, principal, chainedAuthentications, primaryAuthentication, attributes]]>

2019-02-08 11:46:27,255 DEBUG [org.apereo.cas.web.view.Cas30ResponseView] - <Processed principal attributes from the output model to be [[]]>

2019-02-08 11:46:27,255 DEBUG [org.apereo.cas.web.view.Cas30ResponseView] - <CAS is configured to release protocol-level attributes. Processing...>

2019-02-08 11:46:27,255 DEBUG [org.apereo.cas.web.view.Cas30ResponseView] - <Processed protocol/authentication attributes from the output model to be [[samlAuthenticationStatementAuthMethod, credentialType, isFromNewLogin, authenticationDate, authenticationMethod, successfulAuthenticationHandlers, longTermAuthenticationRequestTokenUsed]]>

2019-02-08 11:46:27,256 DEBUG [org.apereo.cas.web.view.Cas30ResponseView] - <Final collection of attributes for the response are [[samlAuthenticationStatementAuthMethod, credentialType, isFromNewLogin, authenticationDate, authenticationMethod, successfulAuthenticationHandlers, longTermAuthenticationRequestTokenUsed]].>

2019-02-08 11:46:27,256 DEBUG [org.apereo.cas.web.view.Cas30ResponseView] - <Beginning to encode attributes for the response>

2019-02-08 11:46:27,256 DEBUG [org.apereo.cas.web.view.Cas30ResponseView] - <Encoded attributes for the response are [{samlAuthenticationStatementAuthMethod=[urn:oasis:names:tc:SAML:1.0:am:password], credentialType=[UsernamePasswordCredential], isFromNewLogin=[true], authenticationDate=[2019-02-08T11:46:26.544+01:00[Europe/Paris]], authenticationMethod=[AcceptUsersAuthenticationHandler], successfulAuthenticationHandlers=[AcceptUsersAuthenticationHandler], longTermAuthenticationRequestTokenUsed=[false]}]>

2019-02-08 11:46:27,256 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Beginning to format/render attributes for the response>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:samlAuthenticationStatementAuthMethod>urn:oasis:names:tc:SAML:1.0:am:password</cas:samlAuthenticationStatementAuthMethod>]>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:credentialType>UsernamePasswordCredential</cas:credentialType>]>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:isFromNewLogin>true</cas:isFromNewLogin>]>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:authenticationDate>2019-02-08T11:46:26.544+01:00[Europe/Paris]</cas:authenticationDate>]>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:authenticationMethod>AcceptUsersAuthenticationHandler</cas:authenticationMethod>]>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:successfulAuthenticationHandlers>AcceptUsersAuthenticationHandler</cas:successfulAuthenticationHandlers>]>

2019-02-08 11:46:27,286 DEBUG [org.apereo.cas.web.view.attributes.DefaultCas30ProtocolAttributesRenderer] - <Formatted attribute for the response: [<cas:longTermAuthenticationRequestTokenUsed>false</cas:longTermAuthenticationRequestTokenUsed>]>

2019-02-08 11:46:27,310 DEBUG [org.jasig.cas.client.validation.Cas30ServiceTicketValidator] - <Server response: <cas:serviceResponse xmlns:cas='http://www.yale.edu/tp/cas'>

<cas:authenticationSuccess>

<cas:user>userPseudo</cas:user>

<cas:attributes>

allUserAttributesAllowed

</cas:attributes>

</cas:authenticationSuccess>

</cas:serviceResponse>

>

2019-02-08 11:46:27,391 WARN [org.apereo.cas.oidc.web.controllers.OidcAuthorizeEndpointController] - <Provided scopes [[]] are undefined by OpenID Connect, which requires that scope [openid] MUST be specified, or the behavior is unspecified. CAS MAY allow this request to be processed for now.>

2019-02-08 11:46:27,394 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Service Access Granted,service=^service.redirect_uri,requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:27 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

>

2019-02-08 11:46:27,394 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN

=============================================================

WHO: audit:unknown

WHAT: [result=Service Access Granted,service=^service.redirect_uri,requiredAttributes={}]

ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED

APPLICATION: CAS

WHEN: Fri Feb 08 11:46:27 CET 2019

CLIENT IP ADDRESS: ip

SERVER IP ADDRESS: ip

=============================================================

Le mercredi 6 février 2019 08:56:47 UTC+1, kyra1510 a écrit :

Message has been deleted

kyra1510

unread,

Feb 13, 2019, 3:01:06 AM2/13/19

to CAS Community

Any help?

I don't know where is the problem.

Le mercredi 6 février 2019 08:56:47 UTC+1, kyra1510 a écrit :

kyra1510

unread,

Feb 14, 2019, 8:38:42 AM2/14/19

to CAS Community

Hi all,

I upgrade my CAS version 5.2.7 to 5.2.8 and everything is working fine.

Le mercredi 6 février 2019 08:56:47 UTC+1, kyra1510 a écrit :

Reply all

Reply to author

Forward