CAS as SAML IdP

1,094 views

Skip to first unread message

Jorge Rodríguez

unread,

Feb 9, 2022, 8:18:32 AM2/9/22

to CAS Community

Hi, I need to test CAS 6.3.7 as SAML IdP provider. For testing purposes I'm trying to integrate NextCloud as SP with CAS IdP.

I have configured CAS to retrieve user attributes from JDBC and the attributes are well defined and working.

I think I'm missing something because I cannot make it to work. These are my config files (related to SAML):

build.gradle:

[..]

//Integracion Auth con SAML2
implementation "org.apereo.cas:cas-server-support-saml-idp:${project.'cas.version'}"
implementation "org.apereo.cas:cas-server-support-saml-idp-metadata:${project.'cas.version'}"
implementation "org.apereo.cas:cas-server-support-saml-idp-web:${project.'cas.version'}"
implementation "org.apereo.cas:cas-server-support-saml-idp-core:${project.'cas.version'}"

-----------------------------

cas.properties:

[...]

cas.saml-core.issuer=cas.demolabdc.local:8443
cas.authn.saml-idp.entity-id=https://cas.demolabdc.local:8443/cas/idp
cas.authn.saml-idp.metadata.location=file:/etc/cas/saml

------------------------

service definition for Nextcloud SP:

ncsaml-2.json:

{
@class: org.apereo.cas.support.saml.services.SamlRegisteredService
serviceId: https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata
name: ncsaml
id: 2
proxyTicketExpirationPolicy:
{
@class: org.apereo.cas.services.DefaultRegisteredServiceProxyTicketExpirationPolicy
}
serviceTicketExpirationPolicy:
{
@class: org.apereo.cas.services.DefaultRegisteredServiceServiceTicketExpirationPolicy
}
evaluationOrder: 2
attributeReleasePolicy:
{
@class: org.apereo.cas.services.ReturnAllAttributeReleasePolicy
}
metadataLocation: /etc/cas/saml/ncsaml-metadata.xml
signingCredentialType: BASIC
encryptableAttributes: null
signingSignatureReferenceDigestMethods: null
signingSignatureAlgorithms: null
signingSignatureBlackListedAlgorithms: null
signingSignatureWhiteListedAlgorithms: null
encryptionDataAlgorithms: null
encryptionKeyAlgorithms: null
encryptionBlackListedAlgorithms: null
encryptionWhiteListedAlgorithms: null
}

----------------------------------

SP metadata file

ncsaml-metadata.xml:

<?xml version="1.0"?>

<md:EntityDescriptor xmlns:md="urn:oasis:names:tc:SAML:2.0:metadata" validUntil="2022-02-11T12:10:20Z" cacheDuration="PT604800S" entityID="https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata">
<md:SPSSODescriptor AuthnRequestsSigned="true" WantAssertionsSigned="true" protocolSupportEnumeration="urn:oasis:names:tc:SAML:2.0:protocol">
<md:KeyDescriptor use="signing">
<ds:KeyInfo xmlns:ds="http://www.w3.org/2000/09/xmldsig#">
<ds:X509Data>
<ds:X509Certificate>xxxxxxxxxCertificateforSigningxxxxxxxxxxx>
</ds:X509Data>
</ds:KeyInfo>
</md:KeyDescriptor>
<md:SingleLogoutService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect" Location="https://ncsaml.demolabdc.local/apps/user_saml/saml/sls"/>
<md:NameIDFormat>urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified</md:NameIDFormat>
<md:AssertionConsumerService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" Location="https://ncsaml.demolabdc.local/apps/user_saml/saml/acs" index="1"/>
</md:SPSSODescriptor>
</md:EntityDescriptor>

----------------------------------

CAS IdP Metadata

idp-metadata.xml:

<?xml version="1.0" encoding="UTF-8"?>
<EntityDescriptor xmlns="urn:oasis:names:tc:SAML:2.0:metadata" xmlns:ds="http://www.w3.org/2000/09/xmldsig#" xmlns:shibmd="urn:mace:shibboleth:metadata:1.0" xmlns:xml="http://www.w3.org/XML/1998/namespace" xmlns:mdui="urn:oasis:names:tc:SAML:metadata:ui" entityID="https://cas.demolabdc.local:8443/cas/idp">
<IDPSSODescriptor protocolSupportEnumeration="urn:oasis:names:tc:SAML:2.0:protocol urn:oasis:names:tc:SAML:1.1:protocol urn:mace:shibboleth:1.0">
<Extensions>
<shibmd:Scope regexp="false">example.org</shibmd:Scope>



</Extensions>
<KeyDescriptor use="signing">
<ds:KeyInfo>
<ds:X509Data>
<ds:X509Certificate>MIIDLjCCAhagAwIBAgIVAKL9QpwhwBoxH01CTCQTnV9o/xl3MA0GCSqGSIb3DQEB
CwUAMB4xHDAaBgNVBAMME2Nhcy5kZW1vbGFiZGMubG9jYWwwHhcNMjIwMjA5MTE0
MzQ1WhcNNDIwMjA5MTE0MzQ1WjAeMRwwGgYDVQQDDBNjYXMuZGVtb2xhYmRjLmxv
Y2FsMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAin776R5qZonDPEjS
Kn96hXlsr1AyezLT8T19lBt6q/lHcNjXDBl68+tsSfyrp1xYA44aXWEkL+UIor3S
iUKIYoCSCALaElcqjRbO5NLkfE4J8Q3tDNo5hYAa3Bnnt8Vc/3udfn/hPSD4q6mb
dWP5rpNer6vAeUAyLair4rVIAENoSJz+6vybWEj8FnsZb3r6zx90X7AP5OFiy8ZP
Gj0uDLovz1pKWj8cDXTilBLtbiqVpG2BIuFN2BBZr1xk4QUC8P2inIZprO1cT4/q
yNoG38D9Foz7c1cC/sSMTQdfP1pu5ZDXNtiTjbJ/yY+F0uAMLA3Zt2nC1uLVq/Qf
62OhnwIDAQABo2MwYTAdBgNVHQ4EFgQUKA0su4DKw79VRN+yfeqCGjKQemIwQAYD
VR0RBDkwN4ITY2FzLmRlbW9sYWJkYy5sb2NhbIYgY2FzLmRlbW9sYWJkYy5sb2Nh
bC9pZHAvbWV0YWRhdGEwDQYJKoZIhvcNAQELBQADggEBAALLBDL8GKcfQYW1k/HW
NpBgqx6yF8/HoMi+5/85+r2Pn8BPgSGyaIveXjJPICAtEmg7A5mFf6ij80JZQihH
LHg23K66S0wVKeyztVO7Urh0FiaR6ZzMcfECRdCRy0IoqiPadHpkLdOolp1Gtjan
+lEK4Li9yLaxMHIJn3Q7hhQUyf0xYKxV6Kmo5yVxK/1UxLliSvRc85rIgl9CRv7c
G6Jk/XWme3v7caGez4hibKA0YmWOZRGtjX05Ih6ExaQgrapxFE3h6RsTt9mRxgam
/yEY75ZKT2BCzssYVKXRf6UKagKQA0vqtoTDZZs0v74v6eC31jsJK48Nh+K56CUC
gBM=</ds:X509Certificate>
</ds:X509Data>
</ds:KeyInfo>
</KeyDescriptor>
<KeyDescriptor use="encryption">
<ds:KeyInfo>
<ds:X509Data>
<ds:X509Certificate>MIIDLTCCAhWgAwIBAgIUOKRP5DfOZRekEsVWy+wA6oB+7/IwDQYJKoZIhvcNAQEL
BQAwHjEcMBoGA1UEAwwTY2FzLmRlbW9sYWJkYy5sb2NhbDAeFw0yMjAyMDkxMTQz
NDZaFw00MjAyMDkxMTQzNDZaMB4xHDAaBgNVBAMME2Nhcy5kZW1vbGFiZGMubG9j
YWwwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQCLqYi6DW1Dz9CuHscs
HLJCz+zfoWssoFtftxAGrYNNFhnB0cXlQnmhOtOyfvDILos4RBx21H9lbsN1XU+p
3A24ZfAdyGH5N9Ap1Q9ecVH4OtmyKPkY6yMzLP3CGZvx+6YNMoOq25fZ+k6W424Y
bl6LAgMsQvBbZQ4CFnSAwhFllzyUGV/cTYRThoxnMgZHHpsBsfUhdqBdzf1UKX7P
6hfQOZA2pcZ2fShQkGaLerlAn7DN646i1WXT41cqtzA2yKlR0cb7lcHk+4EIJevl
6qyrW2Oi+MbBgj4al6xkm7wLKnwFt8hT91suT0aQCXMp4zpVlXs7QVZwsaJx1dWX
OjplAgMBAAGjYzBhMB0GA1UdDgQWBBRctHbfVrcCQphFFih6mjEayXvSrTBABgNV
HREEOTA3ghNjYXMuZGVtb2xhYmRjLmxvY2FshiBjYXMuZGVtb2xhYmRjLmxvY2Fs
L2lkcC9tZXRhZGF0YTANBgkqhkiG9w0BAQsFAAOCAQEALRHKcnnP+GptQoitqk+b
ZpuuNOSl2pmyIXsCsvmwF86EjjnhAjEcukeL8P1LGjzdFwvIZLOB9gqXCLOxZYui
1ZTmFoGVtstuIK9upB16m049pYNcs78ufhek0AVXWQlL6F3rIpZrY2JH30Ea4zVO
ixETHi5noOINTyU5BUG1mLeAmfeK7efjeKK31VKBjanOi9uV5LxpYnsBxjqdOcuP
bAGq9SaaAmth51IHkCN5NvEoU8pXNDTJcaA+sPTy06XVqhSkIuJB7e5LKg64BFb6
yMqd0apuXpEJnb62q8F09Smw5iO6sQaW3YvvTNl3mXEuDMPyiaGYMrW+PEwAN00I
Gg==</ds:X509Certificate>
</ds:X509Data>
</ds:KeyInfo>
</KeyDescriptor>



<SingleLogoutService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" Location="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/POST/SLO"/>
<SingleLogoutService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect" Location="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Redirect/SLO" />

<NameIDFormat>urn:mace:shibboleth:1.0:nameIdentifier</NameIDFormat>
<NameIDFormat>urn:oasis:names:tc:SAML:2.0:nameid-format:transient</NameIDFormat>

<SingleSignOnService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" Location="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/POST/SSO"/>
<SingleSignOnService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST-SimpleSign" Location="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/POST-SimpleSign/SSO"/>
<SingleSignOnService Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect" Location="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Redirect/SSO"/>
<SingleSignOnService Binding="urn:oasis:names:tc:SAML:2.0:bindings:SOAP" Location="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/SOAP/ECP"/>
</IDPSSODescriptor>




</EntityDescriptor>

------------------- When I try to SSO to CAS from Netxcloud I receive a error saying "There was an error with your request", details:

java.lang.NullPointerException at org.apereo.cas.support.saml.web.idp.profile.builders.enc.SamlIdPObjectSigner.configureSignatureSigningSecurityConfiguration(SamlIdPObjectSigner.java:312) at org.apereo.cas.support.saml.web.idp.profile.builders.enc.SamlIdPObjectSigner.getSignatureSigningConfiguration(SamlIdPObjectSigner.java:239) at org.apereo.cas.support.saml.web.idp.profile.builders.enc.SamlIdPObjectSigner.buildSignatureSigningParameters(SamlIdPObjectSigner.java:202) at org.apereo.cas.support.saml.web.idp.profile.builders.enc.SamlIdPObjectSigner.prepareSecurityParametersContext(SamlIdPObjectSigner.java:165) at org.apereo.cas.support.saml.web.idp.profile.builders.enc.SamlIdPObjectSigner.encode(SamlIdPObjectSigner.java:104) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691) at org.apereo.cas.support.saml.web.idp.profile.builders.enc.SamlIdPObjectSigner$$EnhancerBySpringCGLIB$$7c04128d.encode(<generated>) at org.apereo.cas.support.saml.web.idp.profile.builders.assertion.SamlProfileSamlAssertionBuilder.signAssertion(SamlProfileSamlAssertionBuilder.java:129) at org.apereo.cas.support.saml.web.idp.profile.builders.assertion.SamlProfileSamlAssertionBuilder.build(SamlProfileSamlAssertionBuilder.java:101) at org.apereo.cas.support.saml.web.idp.profile.builders.assertion.SamlProfileSamlAssertionBuilder.build(SamlProfileSamlAssertionBuilder.java:37) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy222.build(Unknown Source) at org.apereo.cas.support.saml.web.idp.profile.builders.response.BaseSamlProfileSamlResponseBuilder.buildSamlAssertion(BaseSamlProfileSamlResponseBuilder.java:128) at org.apereo.cas.support.saml.web.idp.profile.builders.response.BaseSamlProfileSamlResponseBuilder.build(BaseSamlProfileSamlResponseBuilder.java:61) at org.apereo.cas.support.saml.web.idp.profile.builders.response.BaseSamlProfileSamlResponseBuilder$$FastClassBySpringCGLIB$$f1322d9c.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88) at org.apereo.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:135) at jdk.internal.reflect.GeneratedMethodAccessor156.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691) at org.apereo.cas.support.saml.web.idp.profile.builders.response.SamlProfileSaml2ResponseBuilder$$EnhancerBySpringCGLIB$$6d977ae.build(<generated>) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy222.build(Unknown Source) at org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController.buildSamlResponse(AbstractSamlIdPProfileHandlerController.java:578) at org.apereo.cas.support.saml.web.idp.profile.sso.SSOSamlIdPProfileCallbackHandlerController.handleCallbackProfileRequest(SSOSamlIdPProfileCallbackHandlerController.java:65) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691) at org.apereo.cas.support.saml.web.idp.profile.sso.SSOSamlIdPProfileCallbackHandlerController$$EnhancerBySpringCGLIB$$1e185896.handleCallbackProfileRequest(<generated>) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:878) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:792) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) at javax.servlet.http.HttpServlet.service(HttpServlet.java:645) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) at javax.servlet.http.HttpServlet.service(HttpServlet.java:750) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apereo.cas.web.support.AuthenticationCredentialsThreadLocalBinderClearingFilter.doFilter(AuthenticationCredentialsThreadLocalBinderClearingFilter.java:28) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apereo.cas.web.support.filters.RequestParameterPolicyEnforcementFilter.doFilter(RequestParameterPolicyEnforcementFilter.java:401) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apereo.cas.web.support.filters.ResponseHeadersEnforcementFilter.doFilter(ResponseHeadersEnforcementFilter.java:200) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apereo.cas.web.support.filters.AddResponseHeadersFilter.doFilter(AddResponseHeadersFilter.java:64) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:204) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:183) at org.springframework.security.web.debug.DebugFilter.invokeWithWrappedRequest(DebugFilter.java:90) at org.springframework.security.web.debug.DebugFilter.doFilter(DebugFilter.java:78) at org.springframework.security.web.debug.DebugFilter.doFilter(DebugFilter.java:67) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apereo.cas.logging.web.ThreadContextMDCServletFilter.doFilter(ThreadContextMDCServletFilter.java:99) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apereo.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:66) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687) at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:769) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1726) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.base/java.lang.Thread.run(Thread.java:829)

------------------ And this is the DEBUG log (at the time of login):

2022-02-09 13:29:22,068 INFO [org.apereo.cas.web.CasWebApplication] - <>
2022-02-09 13:29:22,069 INFO [org.apereo.cas.web.CasWebApplication] - <Ready to process requests @ [2022-02-09T12:29:22.065Z]>
2022-02-09 13:29:22,748 INFO [org.apereo.cas.services.AbstractServicesManager] - <Loaded [3] service(s) from [JsonServiceRegistry].>
2022-02-09 13:29:28,578 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [file:/etc/cas/config/custom_messages_es_ES] - neither plain properties nor XML>
2022-02-09 13:29:28,583 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages_es_ES] - neither plain properties nor XML>
2022-02-09 13:29:28,587 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:messages_es_ES] - neither plain properties nor XML>
2022-02-09 13:29:28,587 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [file:/etc/cas/config/custom_messages_es] - neither plain properties nor XML>
2022-02-09 13:29:28,588 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [file:/etc/cas/config/custom_messages] - neither plain properties nor XML>
2022-02-09 13:29:28,591 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages_es] - neither plain properties nor XML>
2022-02-09 13:29:28,595 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages] - neither plain properties nor XML>
2022-02-09 13:29:28,601 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <Loading properties [messages_es.properties] with encoding 'UTF-8'>
2022-02-09 13:29:28,608 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <Loading properties [messages.properties] with encoding 'UTF-8'>
2022-02-09 13:29:29,824 DEBUG [org.apereo.cas.support.saml.web.idp.profile.sso.request.DefaultSSOSamlHttpRequestExtractor] - <Decoded SAML object [{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest] from http request>
2022-02-09 13:29:29,830 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located issuer [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] from authentication request>
2022-02-09 13:29:29,864 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Checking service access in CAS service registry for [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=null, source=null, loggedOutAlready=false, format=XML, attributes={SigAlg=[http://www.w3.org/2001/04/xmldsig-more#rsa-sha256], SAMLRequest=[nZLfb9sgEMff81dUvCfYblTHKImUNe0WKU2iONvDXioMR4uEwePw2v73xXZ/bJXWh6ETEnd8P9x9xRx5bRq2asO9PcKvFjCMzuJ6rI1F1hcXpPWWOY4ameU1IAuClaubLcsmCWu8C044Qz7IPldxRPBBOzvINusF2e+utvuvm91tKlWVJzmvZKEkTC/SWZ5WoFSaz6DKVcGFSrLztBikP8Bj5CxIxJLRQENsYWMxcBtiPsmycRKjOKUZy4oYPwfpOg6rLQ+9/D6EBhmlguNEQu1MfF9MjBPcsNl0et4VqJYNjQMrbYB2s2T0CFJ7EIGW5X6gHl4M+aKt1Pbucx+q4RKyb6fTYXzYl6cBsnr159JZbGvwJfjfWsD34/a9VSs6oz92S3nTIG2j/rYr037jAsmyJ8+7M+st8sv/INUQuOSBz+mfoHd0w3Zxys364IwWT32+W9fO1zz824x0kvYZLceqv8paiw0IrTRI8oZZGeMeLj3wAAsSfAvkjC5HQy9//+LlMw==], RelayState=[https://ncsaml.demolabdc.local/apps/user_saml/saml/login], Signature=[wWU33tZrTty4rshzB/C1r8OGkHntOvWw57KhaslLA5+lWDXRSaeIx7mtkUUrPfeLanuDPhVrOYlIpnYBp2fbV5tvANzrH2SLMWe1+QQ1TKDHfMYEFbPc0X+l7l8YF5pmEMQvxyg6hcjsb9ixOlGP1cYnefP1LCr5G1UY/zyh/VjyYl2kcvStydUReQwdOOoXRurKtK1ZiGSLAB2hiHMXCllrP3DtkhLVwDb//CtGZx6QN+2VKgzjBuzJhnhtClj9FTagbasVzaxKtDAwe0uYg6c430lDDdM1uac/bXzb+1qKf3I7OPcvWbowylaFA1WbYzBhNEaak6JSh11sRGXMhA==]})]>
2022-02-09 13:29:29,878 DEBUG [org.apereo.cas.support.saml.SamlUtils] - <********************************************************************************>
2022-02-09 13:29:29,992 DEBUG [org.apereo.cas.support.saml.SamlUtils] - <Logging [org.opensaml.saml.saml2.core.impl.AuthnRequestImpl]

[<?xml version="1.0" encoding="UTF-8"?><samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" AssertionConsumerServiceURL="https://ncsaml.demolabdc.local/apps/user_saml/saml/acs" Destination="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Redirect/SSO" ID="ONELOGIN_1dfb707abd9fde461871beff178eb7f9acf02319" IssueInstant="2022-02-09T12:29:29Z" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" Version="2.0">

<saml:Issuer>https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata</saml:Issuer>

<samlp:NameIDPolicy AllowCreate="true" Format="urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified"/>

</samlp:AuthnRequest>
]

>
2022-02-09 13:29:29,994 DEBUG [org.apereo.cas.support.saml.SamlUtils] - <********************************************************************************>
2022-02-09 13:29:30,000 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:30,001 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,011 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceMetadataResolverCacheLoader] - <There are [6] metadata resolver(s) available in the chain>
2022-02-09 13:29:30,013 INFO [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.FileSystemResourceMetadataResolver] - <Loading SAML metadata from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,016 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <No metadata maximum validity criteria is defined for [/etc/cas/saml/ncsaml-metadata.xml], so RequiredValidUntilFilter will not be invoked>
2022-02-09 13:29:30,020 WARN [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <No metadata signature location is defined for [/etc/cas/saml/ncsaml-metadata.xml], so SignatureValidationFilter will not be invoked>
2022-02-09 13:29:30,023 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <Added entity role filter [{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor]>
2022-02-09 13:29:30,027 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <Added entity role filter with roles [[{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor]]>
2022-02-09 13:29:30,029 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <Metadata filter chain initialized with [1] filters>
2022-02-09 13:29:30,031 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <Initializing metadata resolver from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,103 INFO [org.apereo.cas.support.saml.services.idp.metadata.cache.resolver.BaseSamlRegisteredServiceMetadataResolver] - <Initialized metadata resolver from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,113 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceMetadataResolverCacheLoader] - <Metadata resolvers active for this request are [[org.apereo.cas.support.saml.InMemoryResourceMetadataResolver@1fba5655]]>
2022-02-09 13:29:30,138 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceMetadataExpirationPolicy] - <Located cache duration [PT168H] specified in SP metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,142 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,144 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,149 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:30,151 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located SAML service in the registry as [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] with the metadata location of [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,153 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Fetching saml metadata adaptor for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,155 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:30,157 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,170 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,172 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,173 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:30,184 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Validating signature for [org.opensaml.saml.saml2.core.impl.AuthnRequestImpl]>
2022-02-09 13:29:30,203 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Validating request signature for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] via [SAML2HTTPRedirectDeflateSignatureSecurityHandler]...>
2022-02-09 13:29:30,212 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Building security parameters context for signature validation of [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,220 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Resolving signing credentials for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,232 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Signature validation blocked algorithms: [[http://www.w3.org/2001/04/xmldsig-more#hmac-md5, http://www.w3.org/2001/04/xmldsig-more#md5, http://www.w3.org/2001/04/xmldsig-more#rsa-md5]]>
2022-02-09 13:29:30,233 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Signature validation allowed algorithms: [[]]>
2022-02-09 13:29:30,292 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Initializing [SAML2HTTPRedirectDeflateSignatureSecurityHandler] to execute signature validation for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,294 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Invoking [SAML2HTTPRedirectDeflateSignatureSecurityHandler] to handle signature validation for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,334 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.enc.validate.SamlObjectSignatureValidator] - <Successfully validated request signature for [org.opensaml.saml.saml2.core.impl.IssuerImpl@69f3c79].>
2022-02-09 13:29:30,336 DEBUG [org.apereo.cas.support.saml.SamlUtils] - <********************************************************************************>
2022-02-09 13:29:30,341 DEBUG [org.apereo.cas.support.saml.SamlUtils] - <Logging [org.opensaml.saml.saml2.core.impl.AuthnRequestImpl]

[<?xml version="1.0" encoding="UTF-8"?><samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" AssertionConsumerServiceURL="https://ncsaml.demolabdc.local/apps/user_saml/saml/acs" Destination="https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Redirect/SSO" ID="ONELOGIN_1dfb707abd9fde461871beff178eb7f9acf02319" IssueInstant="2022-02-09T12:29:29Z" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" Version="2.0">

<saml:Issuer>https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata</saml:Issuer>

<samlp:NameIDPolicy AllowCreate="true" Format="urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified"/>

</samlp:AuthnRequest>
]

>
2022-02-09 13:29:30,343 DEBUG [org.apereo.cas.support.saml.SamlUtils] - <********************************************************************************>
2022-02-09 13:29:30,370 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Tracking SAML authentication context extension for [{hasBindingSignature=true, relayState=https://ncsaml.demolabdc.local/apps/user_saml/saml/login}]>
2022-02-09 13:29:30,373 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Created service url [https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuse...]>
2022-02-09 13:29:30,374 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Redirecting SAML authN request to [https://cas.demolabdc.local:8443/cas/login?service=https%3A%2F%2Fcas.demolabdc.local%3A8443%2Fcas%2Fidp%2Fprofile%2FSAML2%2FCallback%3FentityId%3Dhttps%253A%252F%252Fncsaml.demolabdc.local%252Fapps%252Fuser_saml%252Fsaml%252Fmetadata]>
2022-02-09 13:29:30,402 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: [result=Service Access Granted,requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:30 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:30,412 DEBUG [org.apereo.cas.web.flow.login.InitialFlowSetupAction] - <Extracted service: [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,414 DEBUG [org.apereo.cas.web.flow.login.InitialFlowSetupAction] - <Placing registered service [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] with id [2] in context scope>
2022-02-09 13:29:30,435 DEBUG [org.apereo.cas.web.flow.authentication.RegisteredServiceAuthenticationPolicySingleSignOnParticipationStrategy] - <Evaluating authentication policy [DefaultRegisteredServiceAuthenticationPolicy(requiredAuthenticationHandlers=[], excludedAuthenticationHandlers=[], criteria=AnyAuthenticationHandlerRegisteredServiceAuthenticationPolicyCriteria(tryAll=false))] for [ncsaml]>
2022-02-09 13:29:30,444 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Resolved single event [success] via [org.apereo.cas.web.flow.resolver.impl.RankedMultifactorAuthenticationProviderWebflowEventResolver] for this context>
2022-02-09 13:29:30,446 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: [event=success,timestamp=Wed Feb 09 13:29:30 CET 2022,source=RankedMultifactorAuthenticationProviderWebflowEventResolver]
ACTION: AUTHENTICATION_EVENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:30 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:30,455 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:30,457 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,459 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:30,460 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:30,461 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:38,311 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: [result=Service Access Granted,requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:38 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:38,419 DEBUG [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] - <User agent [Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:96.0) Gecko/20100101 Firefox/96.0] is authorized to proceed>
2022-02-09 13:29:38,424 DEBUG [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] - <Adaptive authentication policy has authorized client [10.212.134.1] to proceed.>
2022-02-09 13:29:38,426 DEBUG [org.apereo.cas.web.flow.resolver.impl.ServiceTicketRequestWebflowEventResolver] - <Request is not eligible to be issued service tickets just yet>
2022-02-09 13:29:38,447 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication credentials provided for this transaction are [[UsernamePasswordCredential(username=jorge, source=null, customFields={})]]>
2022-02-09 13:29:38,453 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Candidate/Registered authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@38ef1a0a, org.apereo.cas.adaptors.jdbc.QueryDatabaseAuthenticationHandler@58e02359]]>
2022-02-09 13:29:38,455 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.handler.RegisteredServiceAuthenticationHandlerResolver@d1d85d0]]>
2022-02-09 13:29:38,461 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Authentication handler resolvers produced no candidate authentication handler. Using the default handler resolver instead...>
2022-02-09 13:29:38,464 DEBUG [org.apereo.cas.authentication.AuthenticationHandlerResolver] - <Default authentication handlers used for this transaction are [HttpBasedServiceCredentialsAuthenticationHandler,QueryDatabaseAuthenticationHandler]>
2022-02-09 13:29:38,466 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Resolved and finalized authentication handlers to carry out this authentication transaction are [[org.apereo.cas.authentication.handler.RegisteredServiceAuthenticationHandlerResolver@d1d85d0]]>
2022-02-09 13:29:38,467 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate resolved authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@38ef1a0a, org.apereo.cas.adaptors.jdbc.QueryDatabaseAuthenticationHandler@58e02359]]>
2022-02-09 13:29:38,468 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting to authenticate credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})]>
2022-02-09 13:29:38,470 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler [HttpBasedServiceCredentialsAuthenticationHandler] does not support the credential type [UsernamePasswordCredential(username=jorge, source=null, customFields={})]. Trying next...>
2022-02-09 13:29:38,471 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Examining credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})] eligibility for authentication handler [QueryDatabaseAuthenticationHandler]>
2022-02-09 13:29:38,473 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})] eligibility is [QueryDatabaseAuthenticationHandler] for authentication handler [true]>
2022-02-09 13:29:38,473 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting authentication of [jorge] using [QueryDatabaseAuthenticationHandler]>
2022-02-09 13:29:38,519 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Transforming credential username via [org.apereo.cas.util.transforms.ChainingPrincipalNameTransformer]>
2022-02-09 13:29:38,521 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Attempting to encode credential password via [org.springframework.security.crypto.password.NoOpPasswordEncoder] for [jorge]>
2022-02-09 13:29:38,522 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Attempting authentication internally for transformed credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})]>
2022-02-09 13:29:39,726 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler [QueryDatabaseAuthenticationHandler] successfully authenticated [UsernamePasswordCredential(username=jorge, source=null, customFields={})]>
2022-02-09 13:29:39,729 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Invoking principal resolver [PersonDirectoryPrincipalResolver]>
2022-02-09 13:29:39,730 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Extracting credential id based on existing credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})]>
2022-02-09 13:29:39,731 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Principal is currently resolved as [SimplePrincipal(id=jorge, attributes={})]>
2022-02-09 13:29:39,731 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <CAS will NOT be using the identifier from the resolved principal [SimplePrincipal(id=jorge, attributes={})] as it's not configured to use the currently-resolved principal id and will fall back onto using the identifier for the credential, that is [jorge], for principal resolution>
2022-02-09 13:29:39,732 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Extracted principal id [jorge]>
2022-02-09 13:29:39,740 DEBUG [org.apereo.services.persondir.support.AttributeBasedCacheKeyGenerator] - <Generated cache Map {d712a1eeef473d1bdbe4d2ded0c141f5f5de7caf20be7d5f4e99b218cd8cc677e256322171883aa30c1c896b400145f6ca0358bb5d7a6b0de08fdedd9f3d56a6=[jorge]} from seed Map {principal=[jorge], username=[jorge]}>
2022-02-09 13:29:39,743 DEBUG [org.apereo.services.persondir.support.AttributeBasedCacheKeyGenerator] - <Generated cache key '1497567650|1497585262' for MethodInvocation='org.apereo.services.persondir.support.CachingPersonAttributeDaoImpl$PersonAttributeDaoMethodInvocation@5962742f'>
2022-02-09 13:29:39,744 DEBUG [org.apereo.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao] - <Adding attribute 'usuario' with value '[jorge]' to query builder 'null'>
2022-02-09 13:29:39,746 DEBUG [org.apereo.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao] - <Generated query builder 'sql=[usuario = ?] args=[jorge]' from query Map {principal=[jorge], username=[jorge]}.>
2022-02-09 13:29:39,746 DEBUG [org.apereo.services.persondir.support.SimpleUsernameAttributeProvider] - <Using username attribute to get username from the query map>
2022-02-09 13:29:39,747 DEBUG [org.apereo.services.persondir.support.SimpleUsernameAttributeProvider] - <Username attribute value found from the query map is [jorge]>
2022-02-09 13:29:39,767 DEBUG [org.apereo.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao] - <Executed 'SELECT * FROM usuarios WHERE {0}' with arguments [jorge] and got results [{apellidos=Málaga Ocaña, contrasena=Hornet18, correo=jorgem...@gmail.com, id=1, nombre=Jorge, telefono=626084113, usuario=jorge}]>
2022-02-09 13:29:39,796 DEBUG [org.apereo.services.persondir.support.MergingPersonAttributeDaoImpl] - <Retrieved attributes='[NamedPersonImpl[name=jorge,attributes={apellidoscompletos=[Málaga Ocaña], nombreusuario=[jorge], movil=[626084113], nombrepila=[Jorge], correoelectronico=[jorgem...@gmail.com]}]]' for query='{principal=[jorge], username=[jorge]}', isFirstQuery=false, currentlyConsidering='org.apereo.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao@ff1f465', resultAttributes='null'>
2022-02-09 13:29:39,797 DEBUG [org.apereo.services.persondir.support.MergingPersonAttributeDaoImpl] - <Aggregated search results '[NamedPersonImpl[name=jorge,attributes={apellidoscompletos=[Málaga Ocaña], nombreusuario=[jorge], movil=[626084113], nombrepila=[Jorge], correoelectronico=[jorgem...@gmail.com]}]]' for query='{principal=[jorge], username=[jorge]}'>
2022-02-09 13:29:39,799 DEBUG [org.apereo.services.persondir.support.CachingPersonAttributeDaoImpl] - <Retrieved query from wrapped IPersonAttributeDao and stored in cache for scopedTarget.cachingAttributeRepository. key='getPeopleWithMultivaluedAttributes|1497567650|1497585262', results='[NamedPersonImpl[name=jorge,attributes={apellidoscompletos=[Málaga Ocaña], nombreusuario=[jorge], movil=[626084113], nombrepila=[Jorge], correoelectronico=[jorgem...@gmail.com]}]]'>
2022-02-09 13:29:39,807 DEBUG [org.apereo.services.persondir.support.CachingPersonAttributeDaoImpl.statistics] - <Cache Stats scopedTarget.cachingAttributeRepository: queries=1, hits=0, misses=1>
2022-02-09 13:29:39,809 DEBUG [org.apereo.cas.authentication.attribute.PrincipalAttributeRepositoryFetcher] - <Retrieved person [NamedPersonImpl[name=jorge,attributes={apellidoscompletos=[Málaga Ocaña], nombreusuario=[jorge], movil=[626084113], nombrepila=[Jorge], correoelectronico=[jorgem...@gmail.com]}]] from attribute repositories for query [{principal=jorge, username=jorge}]>
2022-02-09 13:29:39,809 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Retrieved [5] attribute(s) from the repository>
2022-02-09 13:29:39,811 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Found attribute [apellidoscompletos] with value(s) [[Málaga Ocaña]]>
2022-02-09 13:29:39,811 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Found attribute [nombreusuario] with value(s) [[jorge]]>
2022-02-09 13:29:39,812 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Found attribute [movil] with value(s) [[626084113]]>
2022-02-09 13:29:39,813 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Found attribute [nombrepila] with value(s) [[Jorge]]>
2022-02-09 13:29:39,813 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Found attribute [correoelectronico] with value(s) [[jorgem...@gmail.com]]>
2022-02-09 13:29:39,814 DEBUG [org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver] - <Final resolved principal by [PersonDirectoryPrincipalResolver] is [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,815 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Resolved principal [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,815 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Invoking principal resolver [EchoingPrincipalResolver]>
2022-02-09 13:29:39,816 DEBUG [org.apereo.cas.authentication.principal.resolvers.EchoingPrincipalResolver] - <Echoing back the authenticated principal [Optional[SimplePrincipal(id=jorge, attributes={})]]>
2022-02-09 13:29:39,817 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Resolved principal [SimplePrincipal(id=jorge, attributes={})]>
2022-02-09 13:29:39,818 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Resolved principal [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,819 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Adding attributes [{apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}] for the final principal>
2022-02-09 13:29:39,822 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}]>
2022-02-09 13:29:39,822 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Resolved principal [SimplePrincipal(id=jorge, attributes={})]>
2022-02-09 13:29:39,824 DEBUG [org.apereo.cas.authentication.principal.DefaultPrincipalElectionStrategy] - <Final principal constructed by the chain of resolvers is [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,839 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <[ChainingPrincipalResolver(principalFactory=org.apereo.cas.authentication.principal.DefaultPrincipalFactory@1, chain=[PersonDirectoryPrincipalResolver(attributeRepository=org.apereo.services.persondir.support.CachingPersonAttributeDaoImpl@8e8ceb3, principalFactory=org.apereo.cas.authentication.principal.DefaultPrincipalFactory@1, returnNullIfNoAttributes=false, principalNameTransformer=org.apereo.cas.authentication.principal.resolvers.PersonDirectoryPrincipalResolver$$Lambda$977/0x00000008407e2440@1a83398e, principalAttributeNames=, useCurrentPrincipalId=false, resolveAttributes=true, activeAttributeRepositoryIdentifiers=[], order=0), EchoingPrincipalResolver()], principalElectionStrategy=org.apereo.cas.authentication.principal.ChainingPrincipalElectionStrategy@78aa1753)] resolved [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] from [UsernamePasswordCredential(username=jorge, source=null, customFields={})]>
2022-02-09 13:29:39,841 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Final principal resolved for this authentication event is [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,844 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Authentication policy resolvers for this transaction are [[org.apereo.cas.authentication.policy.RegisteredServiceAuthenticationPolicyResolver@e4348c0]]>
2022-02-09 13:29:39,850 DEBUG [org.apereo.cas.authentication.policy.RegisteredServiceAuthenticationPolicyResolver] - <Authentication policies for this transaction are [[org.apereo.cas.authentication.policy.AtLeastOneCredentialValidatedAuthenticationPolicy@9769ff6]]>
2022-02-09 13:29:39,852 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Resolved authentication policies are [[org.apereo.cas.authentication.policy.AtLeastOneCredentialValidatedAuthenticationPolicy@9769ff6]]>
2022-02-09 13:29:39,854 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Evaluating authentication principal [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] for inclusion in result>
2022-02-09 13:29:39,855 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}]>
2022-02-09 13:29:39,860 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected principal attributes [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}] for inclusion in this result for principal [jorge]>
2022-02-09 13:29:39,861 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{}]>
2022-02-09 13:29:39,861 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Finalized authentication attributes [{}] for inclusion in this authentication result>
2022-02-09 13:29:39,867 DEBUG [org.apereo.cas.authentication.principal.DefaultPrincipalElectionStrategy] - <Nominated [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] as the primary principal>
2022-02-09 13:29:39,872 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Determined primary authentication principal to be [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,874 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Executing authentication policy [AtLeastOneCredentialValidatedAuthenticationPolicy]>
2022-02-09 13:29:39,878 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Examining credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})] eligibility for authentication handler [QueryDatabaseAuthenticationHandler]>
2022-02-09 13:29:39,882 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})] eligibility is [QueryDatabaseAuthenticationHandler] for authentication handler [true]>
2022-02-09 13:29:39,883 DEBUG [org.apereo.cas.authentication.policy.AtLeastOneCredentialValidatedAuthenticationPolicy] - <Authentication policy is satisfied having found at least one authentication transactions>
2022-02-09 13:29:39,884 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Authentication policy resolvers for this transaction are [[org.apereo.cas.authentication.policy.RegisteredServiceAuthenticationPolicyResolver@e4348c0]]>
2022-02-09 13:29:39,886 DEBUG [org.apereo.cas.authentication.policy.RegisteredServiceAuthenticationPolicyResolver] - <Authentication policies for this transaction are [[org.apereo.cas.authentication.policy.AtLeastOneCredentialValidatedAuthenticationPolicy@9769ff6]]>
2022-02-09 13:29:39,893 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Resolved authentication policies are [[org.apereo.cas.authentication.policy.AtLeastOneCredentialValidatedAuthenticationPolicy@9769ff6]]>
2022-02-09 13:29:39,894 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Evaluating authentication principal [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] for inclusion in result>
2022-02-09 13:29:39,895 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}]>
2022-02-09 13:29:39,896 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected principal attributes [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}] for inclusion in this result for principal [jorge]>
2022-02-09 13:29:39,897 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{}]>
2022-02-09 13:29:39,898 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Finalized authentication attributes [{}] for inclusion in this authentication result>
2022-02-09 13:29:39,899 DEBUG [org.apereo.cas.authentication.principal.DefaultPrincipalElectionStrategy] - <Nominated [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] as the primary principal>
2022-02-09 13:29:39,900 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Determined primary authentication principal to be [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,901 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Executing authentication policy [AtLeastOneCredentialValidatedAuthenticationPolicy]>
2022-02-09 13:29:39,902 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Examining credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})] eligibility for authentication handler [QueryDatabaseAuthenticationHandler]>
2022-02-09 13:29:39,902 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential [UsernamePasswordCredential(username=jorge, source=null, customFields={})] eligibility is [QueryDatabaseAuthenticationHandler] for authentication handler [true]>
2022-02-09 13:29:39,903 DEBUG [org.apereo.cas.authentication.policy.AtLeastOneCredentialValidatedAuthenticationPolicy] - <Authentication policy is satisfied having found at least one authentication transactions>
2022-02-09 13:29:39,906 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication metadata populators for authentication transaction>
2022-02-09 13:29:39,910 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered metadata populators for this transaction are [[SuccessfulHandlerMetaDataPopulator(super=BaseAuthenticationMetaDataPopulator(order=-2147483648)), RememberMeAuthenticationMetaDataPopulator(super=BaseAuthenticationMetaDataPopulator(order=-2147483648)), BaseAuthenticationMetaDataPopulator(order=-2147483648), AuthenticationDateAttributeMetaDataPopulator(super=BaseAuthenticationMetaDataPopulator(order=-2147483648)), CredentialCustomFieldsAttributeMetaDataPopulator(super=BaseAuthenticationMetaDataPopulator(order=-2147483648))]]>
2022-02-09 13:29:39,919 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication post processors for authentication transaction>
2022-02-09 13:29:39,925 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authenticated principal [jorge] with attributes [{apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}] via credentials [[UsernamePasswordCredential(username=jorge, source=null, customFields={})]].>
2022-02-09 13:29:39,929 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: Supplied credentials: [UsernamePasswordCredential(username=jorge, source=null, customFields={})]
ACTION: AUTHENTICATION_SUCCESS
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:39 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:39,933 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: [result=Service Access Granted,service=https://cas.demolabdc.local:8443/cas/...,principal=SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:39 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:39,940 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,944 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,948 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,950 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,953 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,957 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,962 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,964 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,969 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,973 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,978 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,981 DEBUG [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] - <Resolving candidate authentication event for service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] using [DefaultMultifactorAuthenticationProviderWebflowEventResolver]>
2022-02-09 13:29:39,984 DEBUG [org.apereo.cas.web.flow.resolver.impl.AbstractCasWebflowEventResolver] - <Resolved single event [success] via [org.apereo.cas.web.flow.resolver.impl.DefaultCasDelegatingWebflowEventResolver] for this context>
2022-02-09 13:29:39,985 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Evaluating authentication principal [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] for inclusion in result>
2022-02-09 13:29:39,987 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}]>
2022-02-09 13:29:39,988 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected principal attributes [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}] for inclusion in this result for principal [jorge]>
2022-02-09 13:29:39,989 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{credentialType=[UsernamePasswordCredential], authenticationDate=[1644409779], authenticationMethod=[QueryDatabaseAuthenticationHandler], successfulAuthenticationHandlers=[QueryDatabaseAuthenticationHandler]}]>
2022-02-09 13:29:39,989 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Finalized authentication attributes [{credentialType=[UsernamePasswordCredential], authenticationDate=[1644409779], authenticationMethod=[QueryDatabaseAuthenticationHandler], successfulAuthenticationHandlers=[QueryDatabaseAuthenticationHandler]}] for inclusion in this authentication result>
2022-02-09 13:29:39,990 DEBUG [org.apereo.cas.authentication.principal.DefaultPrincipalElectionStrategy] - <Nominated [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] as the primary principal>
2022-02-09 13:29:39,991 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Determined primary authentication principal to be [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:39,991 DEBUG [org.apereo.cas.web.flow.login.CreateTicketGrantingTicketAction] - <Creating ticket-granting ticket, potentially based on []>
2022-02-09 13:29:39,997 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Resolved service [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] from the authentication request>
2022-02-09 13:29:39,999 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: [result=Service Access Granted,service=https://ncsaml.demolabdc.local/apps/u...,principal=SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:39 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,011 DEBUG [org.apereo.cas.ticket.expiration.builder.TicketGrantingTicketExpirationPolicyBuilder] - <Ticket-granting ticket expiration policy is based on hard/idle timeouts of [28800]/[7200] seconds>
2022-02-09 13:29:40,012 DEBUG [org.apereo.cas.ticket.expiration.builder.TicketGrantingTicketExpirationPolicyBuilder] - <Final effective time-to-live of ticket-granting ticket expiration policy is [28800] seconds>
2022-02-09 13:29:40,013 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <Added ticket [TGT-1-*****kGceXzbKK4-cas] to registry.>
2022-02-09 13:29:40,016 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: TGT-1-*****kGceXzbKK4-cas
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:40 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,020 DEBUG [org.apereo.cas.web.flow.authentication.RegisteredServiceAuthenticationPolicySingleSignOnParticipationStrategy] - <Evaluating authentication policy [DefaultRegisteredServiceAuthenticationPolicy(requiredAuthenticationHandlers=[], excludedAuthenticationHandlers=[], criteria=AnyAuthenticationHandlerRegisteredServiceAuthenticationPolicyCriteria(tryAll=false))] for [ncsaml]>
2022-02-09 13:29:40,021 DEBUG [org.apereo.cas.web.flow.login.SendTicketGrantingTicketAction] - <Setting ticket-granting cookie for current session linked to [TGT-1-*****kGceXzbKK4-cas].>
2022-02-09 13:29:40,022 DEBUG [org.apereo.cas.web.support.gen.CookieRetrievingCookieGenerator] - <Request does not indicate a remember-me authentication event. Locating authentication object from the request context...>
2022-02-09 13:29:40,035 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Ticket-granting ticket found in the context is [TGT-1-*****kGceXzbKK4-cas]>
2022-02-09 13:29:40,224 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Registered service asking for service ticket is [SamlRegisteredService(super=AbstractRegisteredService(serviceId=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, name=ncsaml, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=2, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, notifyWhenExpired=false, expirationDate=null), acceptableUsagePolicy=DefaultRegisteredServiceAcceptableUsagePolicy(enabled=true, messageCode=null, text=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, proxyTicketExpirationPolicy=DefaultRegisteredServiceProxyTicketExpirationPolicy(numberOfUses=0, timeToLive=null), proxyGrantingTicketExpirationPolicy=null, ticketGrantingTicketExpirationPolicy=null, serviceTicketExpirationPolicy=DefaultRegisteredServiceServiceTicketExpirationPolicy(numberOfUses=0, timeToLive=null), singleSignOnParticipationPolicy=null, evaluationOrder=2, usernameAttributeProvider=org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider@24cb2c, logoutType=BACK_CHANNEL, environments=[], attributeReleasePolicy=ReturnAllAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(status=UNDEFINED, excludedAttributes=null, includeOnlyAttributes=null, order=0), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null, order=0)), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[], failureMode=UNDEFINED, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false, forceExecution=false, bypassTrustedDeviceEnabled=false, bypassPrincipalAttributeName=null, bypassPrincipalAttributeValue=null, script=null), matchingStrategy=FullRegexRegisteredServiceMatchingStrategy(servicePattern=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata), logo=null, logoutUrl=null, redirectUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[], permitUndefined=true, exclusive=false), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, authenticationPolicy=DefaultRegisteredServiceAuthenticationPolicy(requiredAuthenticationHandlers=[], excludedAuthenticationHandlers=[], criteria=AnyAuthenticationHandlerRegisteredServiceAuthenticationPolicyCriteria(tryAll=false)), properties={}, contacts=[]), metadataLocation=/etc/cas/saml/ncsaml-metadata.xml, metadataProxyLocation=null, metadataMaxValidity=0, requiredAuthenticationContextClass=null, metadataCriteriaDirection=null, metadataCriteriaPattern=null, requiredNameIdFormat=null, metadataSignatureLocation=null, logoutResponseBinding=null, requireSignedRoot=true, serviceProviderNameIdQualifier=null, nameIdQualifier=null, metadataExpirationDuration=PT60M, signingCredentialFingerprint=null, issuerEntityId=null, signingKeyAlgorithm=null, signAssertions=false, signUnsolicitedAuthnRequest=false, skipGeneratingAssertionNameId=false, skipGeneratingSubjectConfirmationInResponseTo=false, skipGeneratingSubjectConfirmationNotOnOrAfter=false, skipGeneratingSubjectConfirmationRecipient=false, skipGeneratingSubjectConfirmationNotBefore=true, skipGeneratingSubjectConfirmationNameId=true, skipGeneratingNameIdQualifiers=false, skipGeneratingTransientNameId=false, signResponses=true, encryptAssertions=false, encryptAttributes=false, encryptionOptional=false, metadataCriteriaRoles=SPSSODescriptor, metadataCriteriaRemoveEmptyEntitiesDescriptors=true, metadataCriteriaRemoveRolelessEntityDescriptors=true, signingCredentialType=BASIC, assertionAudiences=null, skewAllowance=0, whiteListBlackListPrecedence=null, attributeNameFormats={}, attributeFriendlyNames={}, attributeValueTypes={}, encryptableAttributes=null, signingSignatureReferenceDigestMethods=null, signingSignatureAlgorithms=null, signingSignatureBlackListedAlgorithms=null, signingSignatureWhiteListedAlgorithms=null, signingSignatureCanonicalizationAlgorithm=null, encryptionDataAlgorithms=null, encryptionKeyAlgorithms=null, encryptionBlackListedAlgorithms=null, encryptionWhiteListedAlgorithms=null)]>
2022-02-09 13:29:40,224 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Evaluating authentication principal [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] for inclusion in result>
2022-02-09 13:29:40,225 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}]>
2022-02-09 13:29:40,226 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected principal attributes [{nombreusuario=[jorge], movil=[626084113], correoelectronico=[jorgem...@gmail.com], apellidoscompletos=[Málaga Ocaña], nombrepila=[Jorge]}] for inclusion in this result for principal [jorge]>
2022-02-09 13:29:40,226 DEBUG [org.apereo.cas.authentication.CoreAuthenticationUtils] - <Merged attributes with the final result as [{credentialType=[UsernamePasswordCredential], authenticationDate=[1644409779], authenticationMethod=[QueryDatabaseAuthenticationHandler], successfulAuthenticationHandlers=[QueryDatabaseAuthenticationHandler]}]>
2022-02-09 13:29:40,226 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Finalized authentication attributes [{credentialType=[UsernamePasswordCredential], authenticationDate=[1644409779], authenticationMethod=[QueryDatabaseAuthenticationHandler], successfulAuthenticationHandlers=[QueryDatabaseAuthenticationHandler]}] for inclusion in this authentication result>
2022-02-09 13:29:40,230 DEBUG [org.apereo.cas.authentication.principal.DefaultPrincipalElectionStrategy] - <Nominated [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})] as the primary principal>
2022-02-09 13:29:40,230 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Determined primary authentication principal to be [SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]})]>
2022-02-09 13:29:40,240 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: [result=Service Access Granted,service=https://ncsaml.demolabdc.local/apps/u...,requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:40 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,240 DEBUG [org.apereo.cas.services.RegisteredServiceAccessStrategyUtils] - <Current authentication via ticket [TGT-1-*****kGceXzbKK4-cas] allows service [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] to participate in the existing SSO session>
2022-02-09 13:29:40,241 DEBUG [org.apereo.cas.ticket.factory.DefaultServiceTicketFactory] - <Looking up service ticket id generator for [org.apereo.cas.authentication.principal.SimpleWebApplicationServiceImpl]>
2022-02-09 13:29:40,247 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <Added ticket [TGT-1-*****kGceXzbKK4-cas] to registry.>
2022-02-09 13:29:40,249 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <Added ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] to registry.>
2022-02-09 13:29:40,249 INFO [org.apereo.cas.DefaultCentralAuthenticationService] - <Granted service ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] for service [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] and principal [jorge]>
2022-02-09 13:29:40,253 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas for https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuse...
ACTION: SERVICE_TICKET_CREATED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:40 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,256 DEBUG [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Granted service ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] and added it to the request scope>
2022-02-09 13:29:40,257 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] from the context>
2022-02-09 13:29:40,258 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located authentication [org.apereo.cas.authentication.DefaultAuthentication@2d1debb8] from the context>
2022-02-09 13:29:40,258 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] from the context>
2022-02-09 13:29:40,260 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Located service response builder [org.apereo.cas.authentication.principal.WebApplicationServiceResponseBuilder@fe798ee6] for [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>
2022-02-09 13:29:40,265 DEBUG [org.apereo.cas.authentication.principal.DefaultResponse] - <Final redirect response is [https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata&ticket=ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas]>
2022-02-09 13:29:40,266 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Built response [org.apereo.cas.authentication.principal.DefaultResponse@1611db67] for [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>
2022-02-09 13:29:40,266 DEBUG [org.apereo.cas.web.flow.actions.RedirectToServiceAction] - <Signaling flow to redirect to service [AbstractWebApplicationService(id=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, originalUrl=https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuser_saml%2Fsaml%2Fmetadata, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] via event [redirect]>
2022-02-09 13:29:40,289 INFO [org.apereo.cas.support.saml.web.idp.profile.sso.SSOSamlIdPProfileCallbackHandlerController] - <Received SAML callback profile request [/cas/idp/profile/SAML2/Callback]>
2022-02-09 13:29:40,292 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Retrieving authentication request from scope>
2022-02-09 13:29:40,301 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Restoring SAML authentication context extension for [{hasBindingSignature=true, relayState=https://ncsaml.demolabdc.local/apps/user_saml/saml/login}]>
2022-02-09 13:29:40,308 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Tracking SAML authentication context extension for [{hasBindingSignature=false, relayState=https://ncsaml.demolabdc.local/apps/user_saml/saml/login}]>
2022-02-09 13:29:40,310 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Resolved service [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas, principal=null, source=null, loggedOutAlready=false, format=XML, attributes={entityId=[https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]})] from the authentication request with service [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=jorge, source=service, loggedOutAlready=false, format=XML, attributes={})] linked to service ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas]>
2022-02-09 13:29:40,311 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Attribute policy [ReturnAllAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(status=UNDEFINED, excludedAttributes=null, includeOnlyAttributes=null, order=0), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null, order=0))] is associated with service [SamlRegisteredService(super=AbstractRegisteredService(serviceId=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, name=ncsaml, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=2, description=null, expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, notifyWhenExpired=false, expirationDate=null), acceptableUsagePolicy=DefaultRegisteredServiceAcceptableUsagePolicy(enabled=true, messageCode=null, text=null), proxyPolicy=org.apereo.cas.services.RefuseRegisteredServiceProxyPolicy@1, proxyTicketExpirationPolicy=DefaultRegisteredServiceProxyTicketExpirationPolicy(numberOfUses=0, timeToLive=null), proxyGrantingTicketExpirationPolicy=null, ticketGrantingTicketExpirationPolicy=null, serviceTicketExpirationPolicy=DefaultRegisteredServiceServiceTicketExpirationPolicy(numberOfUses=0, timeToLive=null), singleSignOnParticipationPolicy=null, evaluationOrder=2, usernameAttributeProvider=org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider@24cb2c, logoutType=BACK_CHANNEL, environments=[], attributeReleasePolicy=ReturnAllAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(status=UNDEFINED, excludedAttributes=null, includeOnlyAttributes=null, order=0), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null, order=0)), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[], failureMode=UNDEFINED, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false, forceExecution=false, bypassTrustedDeviceEnabled=false, bypassPrincipalAttributeName=null, bypassPrincipalAttributeValue=null, script=null), matchingStrategy=FullRegexRegisteredServiceMatchingStrategy(servicePattern=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata), logo=null, logoutUrl=null, redirectUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[], permitUndefined=true, exclusive=false), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, authenticationPolicy=DefaultRegisteredServiceAuthenticationPolicy(requiredAuthenticationHandlers=[], excludedAuthenticationHandlers=[], criteria=AnyAuthenticationHandlerRegisteredServiceAuthenticationPolicyCriteria(tryAll=false)), properties={}, contacts=[]), metadataLocation=/etc/cas/saml/ncsaml-metadata.xml, metadataProxyLocation=null, metadataMaxValidity=0, requiredAuthenticationContextClass=null, metadataCriteriaDirection=null, metadataCriteriaPattern=null, requiredNameIdFormat=null, metadataSignatureLocation=null, logoutResponseBinding=null, requireSignedRoot=true, serviceProviderNameIdQualifier=null, nameIdQualifier=null, metadataExpirationDuration=PT60M, signingCredentialFingerprint=null, issuerEntityId=null, signingKeyAlgorithm=null, signAssertions=false, signUnsolicitedAuthnRequest=false, skipGeneratingAssertionNameId=false, skipGeneratingSubjectConfirmationInResponseTo=false, skipGeneratingSubjectConfirmationNotOnOrAfter=false, skipGeneratingSubjectConfirmationRecipient=false, skipGeneratingSubjectConfirmationNotBefore=true, skipGeneratingSubjectConfirmationNameId=true, skipGeneratingNameIdQualifiers=false, skipGeneratingTransientNameId=false, signResponses=true, encryptAssertions=false, encryptAttributes=false, encryptionOptional=false, metadataCriteriaRoles=SPSSODescriptor, metadataCriteriaRemoveEmptyEntitiesDescriptors=true, metadataCriteriaRemoveRolelessEntityDescriptors=true, signingCredentialType=BASIC, assertionAudiences=null, skewAllowance=0, whiteListBlackListPrecedence=null, attributeNameFormats={}, attributeFriendlyNames={}, attributeValueTypes={}, encryptableAttributes=null, signingSignatureReferenceDigestMethods=null, signingSignatureAlgorithms=null, signingSignatureBlackListedAlgorithms=null, signingSignatureWhiteListedAlgorithms=null, signingSignatureCanonicalizationAlgorithm=null, encryptionDataAlgorithms=null, encryptionKeyAlgorithms=null, encryptionBlackListedAlgorithms=null, encryptionWhiteListedAlgorithms=null)]>
2022-02-09 13:29:40,313 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Initiating attributes release phase for principal [jorge] accessing service [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=jorge, source=service, loggedOutAlready=false, format=XML, attributes={})] defined by registered service [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]...>
2022-02-09 13:29:40,313 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Using principal attribute repository [DefaultPrincipalAttributesRepository()] to retrieve attributes>
2022-02-09 13:29:40,315 DEBUG [org.apereo.cas.authentication.principal.DefaultPrincipalAttributesRepository] - <Using [jorge], no caching takes place for [DefaultPrincipalAttributesRepository] to add attributes.>
2022-02-09 13:29:40,315 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Found principal attributes [{nombreusuario=[jorge], movil=[626084113], apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], nombrepila=[Jorge]}] for [jorge]>
2022-02-09 13:29:40,316 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Attribute policy [ReturnAllAttributeReleasePolicy] allows release of [{nombreusuario=[jorge], movil=[626084113], apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], nombrepila=[Jorge]}] for [jorge]>
2022-02-09 13:29:40,317 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Default attributes for release are: [[]]>
2022-02-09 13:29:40,317 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Default attributes found to be released are [{}]>
2022-02-09 13:29:40,318 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Finalizing attributes release phase for principal [jorge] accessing service [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=jorge, source=service, loggedOutAlready=false, format=XML, attributes={})] defined by registered service [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]...>
2022-02-09 13:29:40,318 DEBUG [org.apereo.cas.services.AbstractRegisteredServiceAttributeReleasePolicy] - <Final collection of attributes allowed are: [{apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}]>
2022-02-09 13:29:40,319 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Calculated attributes for release per the release policy are [[apellidoscompletos, correoelectronico, movil, nombrepila, nombreusuario]]>
2022-02-09 13:29:40,319 DEBUG [org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider] - <Returning the default principal id [jorge] for username.>
2022-02-09 13:29:40,320 DEBUG [org.apereo.cas.services.BaseRegisteredServiceUsernameAttributeProvider] - <Resolved username for [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=jorge, source=service, loggedOutAlready=false, format=XML, attributes={})] is [jorge]>
2022-02-09 13:29:40,321 DEBUG [org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider] - <Returning the default principal id [jorge] for username.>
2022-02-09 13:29:40,321 DEBUG [org.apereo.cas.services.BaseRegisteredServiceUsernameAttributeProvider] - <Resolved username for [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=null, principal=jorge, source=service, loggedOutAlready=false, format=XML, attributes={})] is [jorge]>
2022-02-09 13:29:40,322 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Principal determined for release to [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] is [jorge]>
2022-02-09 13:29:40,323 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: [result=Service Access Granted,service=https://ncsaml.demolabdc.local/apps/u...,principal=SimplePrincipal(id=jorge, attributes={apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:40 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,326 DEBUG [org.apereo.cas.ticket.expiration.MultiTimeUseOrTimeoutExpirationPolicy] - <Ticket usage count [1] is greater than or equal to [1]. Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] has expired>
2022-02-09 13:29:40,327 DEBUG [org.apereo.cas.ticket.expiration.MultiTimeUseOrTimeoutExpirationPolicy] - <Ticket usage count [1] is greater than or equal to [1]. Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] has expired>
2022-02-09 13:29:40,327 DEBUG [org.apereo.cas.ticket.registry.AbstractTicketRegistry] - <Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] has expired and is now removed from the ticket registry>
2022-02-09 13:29:40,328 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <The condition enforced by the predicate [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] cannot successfully accept/test the ticket id [AbstractTicketRegistry$$Lambda$1546/0x0000000840d57c40]>
2022-02-09 13:29:40,330 DEBUG [org.apereo.cas.ticket.registry.AbstractTicketRegistry] - <Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] could not be fetched from the registry; it may have been expired and deleted.>
2022-02-09 13:29:40,332 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas for https://cas.demolabdc.local:8443/cas/idp/profile/SAML2/Callback?entityId=https%3A%2F%2Fncsaml.demolabdc.local%2Fapps%2Fuse...
ACTION: SERVICE_TICKET_VALIDATE_SUCCESS
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:40 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,337 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:40,337 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,338 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,339 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,339 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:40,341 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion Valid: [true]>
2022-02-09 13:29:40,341 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion Principal: [jorge]>
2022-02-09 13:29:40,342 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion authentication Date: [2022-02-09T13:29:40.341+0100]>
2022-02-09 13:29:40,342 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion ValidFrom Date: [2022-02-09T13:29:40.341+0100]>
2022-02-09 13:29:40,343 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion ValidUntil Date: [null]>
2022-02-09 13:29:40,343 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion Attributes: [{credentialType=[UsernamePasswordCredential], authenticationDate=[2022-02-09T12:29:39.991629Z], authenticationMethod=[QueryDatabaseAuthenticationHandler], successfulAuthenticationHandlers=[QueryDatabaseAuthenticationHandler], isFromNewLogin=[true], longTermAuthenticationRequestTokenUsed=[false]}]>
2022-02-09 13:29:40,344 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <CAS Assertion Principal Attributes: [{apellidoscompletos=[Málaga Ocaña], correoelectronico=[jorgem...@gmail.com], movil=[626084113], nombrepila=[Jorge], nombreusuario=[jorge]}]>
2022-02-09 13:29:40,345 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located issuer [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] from authentication context>
2022-02-09 13:29:40,345 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Checking service access in CAS service registry for [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas, principal=null, source=null, loggedOutAlready=false, format=XML, attributes={entityId=[https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]})]>
2022-02-09 13:29:40,346 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:40,347 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,347 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,351 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,351 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:40,352 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located SAML service in the registry as [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] with the metadata location of [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,352 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located SAML metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,353 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:40,353 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,354 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,354 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,355 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:40,356 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Determined authentication request binding is [urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST], issued by [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,356 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Checking metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] to see if binding [urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST] is supported>
2022-02-09 13:29:40,357 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Binding [urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST] is supported by [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,358 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located issuer [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] from authentication context>
2022-02-09 13:29:40,359 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Checking service access in CAS service registry for [AbstractWebApplicationService(id=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, originalUrl=https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata, artifactId=ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas, principal=null, source=null, loggedOutAlready=false, format=XML, attributes={entityId=[https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]})]>
2022-02-09 13:29:40,359 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:40,360 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,361 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,361 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,362 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:40,362 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located SAML service in the registry as [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] with the metadata location of [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,363 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Located SAML metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,363 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Locating metadata for entityID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] by attempting to run through the metadata chain...>
2022-02-09 13:29:40,363 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Resolving metadata for [ncsaml] at [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,367 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.cache.SamlRegisteredServiceDefaultCachingMetadataResolver] - <Loaded and cached SAML metadata [org.opensaml.saml.metadata.resolver.ChainingMetadataResolver] from [/etc/cas/saml/ncsaml-metadata.xml]>
2022-02-09 13:29:40,367 INFO [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Resolved metadata chain from [/etc/cas/saml/ncsaml-metadata.xml]. Filtering the chain by entity ID [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,367 DEBUG [org.apereo.cas.support.saml.services.idp.metadata.SamlRegisteredServiceServiceProviderMetadataFacade] - <Located SP SSODescriptor in metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]. Metadata is valid until [forever]>
2022-02-09 13:29:40,367 DEBUG [org.apereo.cas.support.saml.web.idp.profile.AbstractSamlIdPProfileHandlerController] - <Preparing SAML response for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,376 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.authn.DefaultAuthnContextClassRefBuilder] - <No specific authN context is requested. Returning [urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport]>
2022-02-09 13:29:40,382 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.authn.SamlProfileSamlAuthNStatementBuilder] - <Built subject locality address [10.238.228.251] for the saml authentication statement prepped for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]>
2022-02-09 13:29:40,383 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [credentialType] to [credentialType] with value(s) [[UsernamePasswordCredential]]>
2022-02-09 13:29:40,384 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [nombreusuario] to [nombreusuario] with value(s) [[jorge]]>
2022-02-09 13:29:40,384 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [isFromNewLogin] to [isFromNewLogin] with value(s) [[true]]>
2022-02-09 13:29:40,385 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [movil] to [movil] with value(s) [[626084113]]>
2022-02-09 13:29:40,385 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [authenticationDate] to [authenticationDate] with value(s) [[2022-02-09T12:29:39.991629Z]]>
2022-02-09 13:29:40,385 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [authenticationMethod] to [authenticationMethod] with value(s) [[QueryDatabaseAuthenticationHandler]]>
2022-02-09 13:29:40,386 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [successfulAuthenticationHandlers] to [successfulAuthenticationHandlers] with value(s) [[QueryDatabaseAuthenticationHandler]]>
2022-02-09 13:29:40,386 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [longTermAuthenticationRequestTokenUsed] to [longTermAuthenticationRequestTokenUsed] with value(s) [[false]]>
2022-02-09 13:29:40,387 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [apellidoscompletos] to [apellidoscompletos] with value(s) [[Málaga Ocaña]]>
2022-02-09 13:29:40,387 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [correoelectronico] to [correoelectronico] with value(s) [[jorgem...@gmail.com]]>
2022-02-09 13:29:40,388 DEBUG [org.apereo.cas.authentication.ProtocolAttributeEncoder] - <Decoded SAML attribute [nombrepila] to [nombrepila] with value(s) [[Jorge]]>
2022-02-09 13:29:40,392 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [credentialType] with values [[UsernamePasswordCredential]]>
2022-02-09 13:29:40,396 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [credentialType]>
2022-02-09 13:29:40,396 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [credentialType] has [1] value(s)>
2022-02-09 13:29:40,397 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [credentialType]>
2022-02-09 13:29:40,398 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [nombreusuario] with values [[jorge]]>
2022-02-09 13:29:40,398 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [nombreusuario]>
2022-02-09 13:29:40,399 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [nombreusuario] has [1] value(s)>
2022-02-09 13:29:40,399 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [nombreusuario]>
2022-02-09 13:29:40,400 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [isFromNewLogin] with values [[true]]>
2022-02-09 13:29:40,400 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [isFromNewLogin]>
2022-02-09 13:29:40,400 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [isFromNewLogin] has [1] value(s)>
2022-02-09 13:29:40,401 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [isFromNewLogin]>
2022-02-09 13:29:40,402 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [movil] with values [[626084113]]>
2022-02-09 13:29:40,402 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [movil]>
2022-02-09 13:29:40,403 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [movil] has [1] value(s)>
2022-02-09 13:29:40,403 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [movil]>
2022-02-09 13:29:40,404 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [authenticationDate] with values [[2022-02-09T12:29:39.991629Z]]>
2022-02-09 13:29:40,404 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [authenticationDate]>
2022-02-09 13:29:40,405 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [authenticationDate] has [1] value(s)>
2022-02-09 13:29:40,405 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [authenticationDate]>
2022-02-09 13:29:40,406 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [authenticationMethod] with values [[QueryDatabaseAuthenticationHandler]]>
2022-02-09 13:29:40,406 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [authenticationMethod]>
2022-02-09 13:29:40,407 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [authenticationMethod] has [1] value(s)>
2022-02-09 13:29:40,407 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [authenticationMethod]>
2022-02-09 13:29:40,408 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [successfulAuthenticationHandlers] with values [[QueryDatabaseAuthenticationHandler]]>
2022-02-09 13:29:40,409 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [successfulAuthenticationHandlers]>
2022-02-09 13:29:40,409 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [successfulAuthenticationHandlers] has [1] value(s)>
2022-02-09 13:29:40,409 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [successfulAuthenticationHandlers]>
2022-02-09 13:29:40,410 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [longTermAuthenticationRequestTokenUsed] with values [[false]]>
2022-02-09 13:29:40,413 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [longTermAuthenticationRequestTokenUsed]>
2022-02-09 13:29:40,416 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [longTermAuthenticationRequestTokenUsed] has [1] value(s)>
2022-02-09 13:29:40,416 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [longTermAuthenticationRequestTokenUsed]>
2022-02-09 13:29:40,417 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [apellidoscompletos] with values [[Málaga Ocaña]]>
2022-02-09 13:29:40,417 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [apellidoscompletos]>
2022-02-09 13:29:40,418 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [apellidoscompletos] has [1] value(s)>
2022-02-09 13:29:40,418 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [apellidoscompletos]>
2022-02-09 13:29:40,419 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [correoelectronico] with values [[jorgem...@gmail.com]]>
2022-02-09 13:29:40,419 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [correoelectronico]>
2022-02-09 13:29:40,420 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [correoelectronico] has [1] value(s)>
2022-02-09 13:29:40,420 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [correoelectronico]>
2022-02-09 13:29:40,421 DEBUG [org.apereo.cas.support.saml.util.AbstractSamlObjectBuilder] - <Generating multi-valued SAML attribute [nombrepila] with values [[Jorge]]>
2022-02-09 13:29:40,423 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Skipped name format, as no name formats are defined or none is found for attribute [nombrepila]>
2022-02-09 13:29:40,423 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Attribute [nombrepila] has [1] value(s)>
2022-02-09 13:29:40,423 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.attr.SamlProfileSamlRegisteredServiceAttributeBuilder] - <Service [ncsaml] is configured to not encrypt attributes for [nombrepila]>
2022-02-09 13:29:40,426 DEBUG [org.apereo.cas.support.saml.SamlIdPUtils] - <Fetched assertion consumer service url [https://ncsaml.demolabdc.local/apps/user_saml/saml/acs] with binding [urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST] from authentication request>
2022-02-09 13:29:40,426 DEBUG [org.apereo.cas.support.saml.SamlIdPUtils] - <Checking SAML authentication extensions [[org.opensaml.saml.saml2.core.impl.AttributeImpl@7fe323ea]]>
2022-02-09 13:29:40,428 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Metadata for [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] declares the following NameIDs [[urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified]]>
2022-02-09 13:29:40,429 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <AuthN request indicates [urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified] is the required NameID format>
2022-02-09 13:29:40,429 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Evaluating NameID format [urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified]>
2022-02-09 13:29:40,431 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Preparing NameID attribute for principal [jorge]>
2022-02-09 13:29:40,431 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <NameID attribute value is set to [jorge]>
2022-02-09 13:29:40,441 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlAttributeBasedNameIdGenerator] - <NameID SP qualifier is set to [null]>
2022-02-09 13:29:40,441 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Encoding NameID based on [urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified]>
2022-02-09 13:29:40,442 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Final NameID encoded with format [urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified] has value [jorge]>
2022-02-09 13:29:40,443 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Determined NameID based on format [urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified] to be [jorge]>
2022-02-09 13:29:40,443 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.nameid.SamlProfileSamlNameIdBuilder] - <Required NameID format assigned to service [ncsaml] is [urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified]>
2022-02-09 13:29:40,443 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Building subject for NameID [org.opensaml.saml.saml2.core.impl.NameIDImpl@7bc0618d] and recipient [https://ncsaml.demolabdc.local/apps/user_saml/saml/acs], in response to [ONELOGIN_1dfb707abd9fde461871beff178eb7f9acf02319]>
2022-02-09 13:29:40,446 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Built subject [org.opensaml.saml.saml2.core.impl.SubjectImpl@6c248db7]>
2022-02-09 13:29:40,447 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.subject.SamlProfileSamlSubjectBuilder] - <Created SAML subject [org.opensaml.saml.saml2.core.impl.SubjectImpl@6c248db7]>
2022-02-09 13:29:40,447 DEBUG [org.apereo.cas.support.saml.util.AbstractSaml20ObjectBuilder] - <Building conditions for audience [[https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata]] that enforce not-before [2022-02-09T12:29:25.447582Z] and not-after [2022-02-09T12:29:55.447582Z]>
2022-02-09 13:29:40,451 DEBUG [org.apereo.cas.support.saml.web.idp.profile.builders.assertion.SamlProfileSamlAssertionBuilder] - <SAML registered service [https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata] requires assertions to be signed>
2022-02-09 13:29:40,452 DEBUG [org.apereo.cas.support.saml.SamlIdPUtils] - <Fetched assertion consumer service url [https://ncsaml.demolabdc.local/apps/user_saml/saml/acs] with binding [urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST] from authentication request>
2022-02-09 13:29:40,452 DEBUG [org.apereo.cas.support.saml.SamlIdPUtils] - <Checking SAML authentication extensions [[org.opensaml.saml.saml2.core.impl.AttributeImpl@7fe323ea]]>
2022-02-09 13:29:40,453 DEBUG [org.apereo.cas.support.saml.SamlIdPUtils] - <Configured peer entity endpoint to be [https://ncsaml.demolabdc.local/apps/user_saml/saml/acs] with binding [urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST]>
2022-02-09 13:29:40,454 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: jorge
WHAT: java.lang.NullPointerException
ACTION: SAML2_RESPONSE_CREATED
APPLICATION: CAS
WHEN: Wed Feb 09 13:29:40 CET 2022
CLIENT IP ADDRESS: 10.212.134.1
SERVER IP ADDRESS: 10.238.228.251
=============================================================

>
2022-02-09 13:29:40,470 DEBUG [org.apereo.cas.web.FlowExecutionExceptionResolver] - <Ignoring the received exception [java.lang.NullPointerException] due to a type mismatch with handler [org.apereo.cas.support.saml.web.idp.profile.sso.SSOSamlIdPProfileCallbackHandlerController#handleCallbackProfileRequest(HttpServletResponse, HttpServletRequest)]>
2022-02-09 13:29:40,470 DEBUG [org.apereo.cas.web.FlowExecutionExceptionResolver] - <Ignoring the received exception [java.lang.NullPointerException] due to a type mismatch with handler [org.apereo.cas.support.saml.web.idp.profile.sso.SSOSamlIdPProfileCallbackHandlerController#handleCallbackProfileRequest(HttpServletResponse, HttpServletRequest)]>
2022-02-09 13:29:40,476 ERROR [org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/cas].[dispatcherServlet]] - <Servlet.service() for servlet [dispatcherServlet] in context with path [/cas] threw exception [Request processing failed; nested exception is java.lang.NullPointerException] with root cause>

-----------------------------

Any clue? I don't know what to do next...

Jorge

Ray Bon

unread,

Feb 9, 2022, 8:14:28 PM2/9/22

to cas-...@apereo.org

Jorge,

Try removing the signing and encryption lines (the ones that are null) from the service definition.

Ray

On Wed, 2022-02-09 at 04:32 -0800, Jorge Rodríguez wrote:

Notice: This message was sent from outside the University of Victoria email system. Please be cautious with links and sensitive information.

--

Ray Bon

Programmer Analyst

Development Services, University Systems

2507218831 | CLE 019 | rb...@uvic.ca

I acknowledge and respect the lək̓ʷəŋən peoples on whose traditional territory the university stands, and the Songhees, Esquimalt and WSÁNEĆ peoples whose historical relationships with the land continue to this day.

Andrew Marker

unread,

Feb 9, 2022, 8:14:50 PM2/9/22

to cas-...@apereo.org

This, seems strange. I don't know if it is a clue, but I would verify that the # of uses is greater than 0 in our cas.properties file. This is what I have.

# Ticket Registry
cas.ticket.tgt.timeToKillInSeconds=7200
cas.ticket.tgt.maxTimeToLiveInSeconds=28800

# Service Tickets
cas.ticket.st.numberOfUses=1
cas.ticket.st.timeToKillInSeconds=30

serviceTicketExpirationPolicy=DefaultRegisteredServiceServiceTicketExpirationPolicy(numberOfUses=0, timeToLive=null),

2022-02-09 13:29:40,326 DEBUG [org.apereo.cas.ticket.expiration.MultiTimeUseOrTimeoutExpirationPolicy] - <Ticket usage count [1] is greater than or equal to [1]. Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] has expired>
2022-02-09 13:29:40,327 DEBUG [org.apereo.cas.ticket.expiration.MultiTimeUseOrTimeoutExpirationPolicy] - <Ticket usage count [1] is greater than or equal to [1]. Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] has expired>
2022-02-09 13:29:40,327 DEBUG [org.apereo.cas.ticket.registry.AbstractTicketRegistry] - <Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] has expired and is now removed from the ticket registry>
2022-02-09 13:29:40,328 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <The condition enforced by the predicate [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] cannot successfully accept/test the ticket id [AbstractTicketRegistry$$Lambda$1546/0x0000000840d57c40]>
2022-02-09 13:29:40,330 DEBUG [org.apereo.cas.ticket.registry.AbstractTicketRegistry] - <Ticket [ST-1-PmNPIJyLQrG9EY4XGyTQ3DTg9g8-cas] could not be fetched from the registry; it may have been expired and deleted.>

--
- Website: https://apereo.github.io/cas
- Gitter Chatroom: https://gitter.im/apereo/cas
- List Guidelines: https://goo.gl/1VRrw7
- Contributions: https://goo.gl/mh7qDG
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/52fe429b-5ae4-48f1-adfd-0d067e09f8ean%40apereo.org.

Jorge Rodríguez

unread,

Feb 10, 2022, 5:54:37 AM2/10/22

to cas-...@apereo.org

Hi Ray,

I've done it, but at SP side I received an error telling that "Signature validation failed. SAML Response rejected".

Jorge

--

- Website: https://apereo.github.io/cas
- Gitter Chatroom: https://gitter.im/apereo/cas
- List Guidelines: https://goo.gl/1VRrw7
- Contributions: https://goo.gl/mh7qDG
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/b5b603342ead42dce09171c2bd337e0602687b5d.camel%40uvic.ca.

Jorge Rodríguez

unread,

Feb 10, 2022, 7:21:10 AM2/10/22

to cas-...@apereo.org

Hi Andrew,

i have changed the values, but the problem persists. I understand that the IdP certificate I have to configure at the SP side is the IdP signing certificate, right?

Jorge

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAGGVe%2BHf0XWjPPmfeeXHvD3DjrTkN0xj8zS1jbjmxRYGGKwNCw%40mail.gmail.com.

Ray Bon

unread,

Feb 11, 2022, 11:27:50 PM2/11/22

to cas-...@apereo.org

Jorge,

That is correct.

You will either set up the SP by supplying IdP metadata or filling in a web form.

The SP will get what it needs from IdP metadata or if you fill in a web form, there would be a place to paste or upload the public signing cert.

Ray

On Thu, 2022-02-10 at 12:52 +0100, Jorge Rodríguez wrote:

Notice: This message was sent from outside the University of Victoria email system. Please be cautious with links and sensitive information.

Ray Bon

unread,

Feb 11, 2022, 11:27:50 PM2/11/22

to cas-...@apereo.org

Jorge,

Use a tool like SAML-tracer to see what the saml looks like (signed, encrypted, attributes if not encrypted,

etc).

Ray

Jorge Rodríguez

unread,

Feb 15, 2022, 7:37:59 AM2/15/22

to CAS Community, Ray Bon

Hi all, I've been enable to make it work. Don't ask me how or what have I changed cause i don't really know. I paste here the service definition if it helps to others:

{
"@class" : "org.apereo.cas.support.saml.services.SamlRegisteredService",
"serviceId" : "https://ncsaml.demolabdc.local/apps/user_saml/saml/metadata",
"name" : "ncsaml",
"id" : 2,
"evaluationOrder" : 1,
"attributeReleasePolicy" : {
"@class" : "org.apereo.cas.services.ReturnAllAttributeReleasePolicy"
},
"usernameAttributeProvider" : {
"@class" : "org.apereo.cas.services.PrincipalAttributeRegisteredServiceUsernameProvider",
"usernameAttribute" : "nombreusuario"
}
"metadataLocation" : "/etc/cas/saml/ncsaml-metadata.xml",
"metadataSignatureLocation" : "/etc/cas/saml/idp-signing.crt"
}

Regards.

Jorge

Reply all

Reply to author

Forward

0 new messages