here are the debug logs
GLUU.root@sso:/opt/shibboleth-idp/conf# tail -f /opt/shibboleth-idp/logs/idp-process.log
2017-07-19 22:16:56,760 - INFO [net.shibboleth.utilities.java.support.service.AbstractReloadableService:258] - Service 'shibboleth.ReloadableCASServiceRegistry': Reloading service configuration
2017-07-19 22:16:56,761 - INFO [net.shibboleth.ext.spring.util.SchemaTypeAwareXMLBeanDefinitionReader:317] - Loading XML bean definitions from file [/opt/shibboleth-idp/conf/cas-protocol.xml]
2017-07-19 22:16:56,766 - INFO [net.shibboleth.ext.spring.context.FilesystemGenericApplicationContext:577] - Refreshing ApplicationContext:shibboleth.ReloadableCASServiceRegistry: startup date [Wed Jul 19 22:16:56 UTC 2017]; parent: Root WebApplicationContext
2017-07-19 22:16:56,778 - INFO [net.shibboleth.ext.spring.service.ReloadableSpringService:378] - Service 'shibboleth.ReloadableCASServiceRegistry': Completed reload and swapped in latest configuration for service 'shibboleth.ReloadableCASServiceRegistry'
2017-07-19 22:16:56,778 - INFO [net.shibboleth.ext.spring.context.FilesystemGenericApplicationContext:957] - Closing ApplicationContext:shibboleth.ReloadableCASServiceRegistry: startup date [Wed Jul 19 22:01:56 UTC 2017]; parent: Root WebApplicationContext
2017-07-19 22:16:56,783 - INFO [net.shibboleth.ext.spring.service.ReloadableSpringService:385] - Service 'shibboleth.ReloadableCASServiceRegistry': Reload complete
2017-07-19 22:16:56,802 - INFO [net.shibboleth.ext.spring.config.DurationToLongConverter:48] - Deprecated duration of 300000 was specified. Use XML duration of P0Y0M0DT0H5M0.000S
2017-07-19 22:16:56,848 - INFO [net.shibboleth.ext.spring.service.ReloadableSpringService:378] - Service 'shibboleth.RelyingPartyResolverService': Completed reload and swapped in latest configuration for service 'shibboleth.RelyingPartyResolverService'
2017-07-19 22:16:56,848 - INFO [net.shibboleth.ext.spring.context.FilesystemGenericApplicationContext:957] - Closing ApplicationContext:shibboleth.RelyingPartyResolverService: startup date [Wed Jul 19 22:01:56 UTC 2017]; parent: Root WebApplicationContext
2017-07-19 22:16:56,854 - INFO [net.shibboleth.ext.spring.service.ReloadableSpringService:385] - Service 'shibboleth.RelyingPartyResolverService': Reload complete
2017-07-19 22:19:02,567 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.impl.CheckMessageVersionHandler' on INBOUND message context
2017-07-19 22:19:02,568 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,569 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml1.binding.impl.SAML1ArtifactRequestIssuerHandler' on INBOUND message context
2017-07-19 22:19:02,569 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,571 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.impl.SAMLProtocolAndRoleHandler' on INBOUND message context
2017-07-19 22:19:02,573 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,578 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.impl.SAMLMetadataLookupHandler' on INBOUND message context
2017-07-19 22:19:02,580 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,582 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.impl.SAMLAddAttributeConsumingServiceHandler' on INBOUND message context
2017-07-19 22:19:02,584 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,584 - DEBUG [net.shibboleth.idp.saml.profile.impl.InitializeRelyingPartyContextFromSAMLPeer:132] - Profile Action InitializeRelyingPartyContextFromSAMLPeer: Attaching RelyingPartyContext based on SAML peer https://blah.webex.com
2017-07-19 22:19:02,585 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:293] - Resolving relying party configuration
2017-07-19 22:19:02,586 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:305] - Checking if relying party configuration EntityNames[https://blah.webex.com,] is applicable
2017-07-19 22:19:02,587 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:307] - Relying party configuration EntityNames[https://blah.webex.com,] is applicable
2017-07-19 22:19:02,587 - DEBUG [net.shibboleth.idp.profile.impl.SelectRelyingPartyConfiguration:136] - Profile Action SelectRelyingPartyConfiguration: Found relying party configuration EntityNames[https://blah.webex.com,] for request
2017-07-19 22:19:02,592 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.PopulateProfileInterceptorContext:126] - Profile Action PopulateProfileInterceptorContext: Installing flow intercept/security-policy/saml2-sso into interceptor context
2017-07-19 22:19:02,594 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.FilterFlowsByNonBrowserSupport:52] - Profile Action FilterFlowsByNonBrowserSupport: Request does not have non-browser requirement, nothing to do
2017-07-19 22:19:02,595 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:101] - Profile Action SelectProfileInterceptorFlow: Checking flow intercept/security-policy/saml2-sso for applicability...
2017-07-19 22:19:02,595 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:84] - Profile Action SelectProfileInterceptorFlow: Selecting flow intercept/security-policy/saml2-sso
2017-07-19 22:19:02,598 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.ReceivedEndpointSecurityHandler' on INBOUND message context
2017-07-19 22:19:02,599 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,601 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler' on INBOUND message context
2017-07-19 22:19:02,602 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,606 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.MessageLifetimeSecurityHandler' on INBOUND message context
2017-07-19 22:19:02,606 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,609 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2AuthnRequestsSignedSecurityHandler' on INBOUND message context
2017-07-19 22:19:02,609 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,610 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.common.binding.security.impl.SAMLProtocolMessageXMLSignatureSecurityHandler' on INBOUND message context
2017-07-19 22:19:02,613 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,615 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2HTTPRedirectDeflateSignatureSecurityHandler' on INBOUND message context
2017-07-19 22:19:02,615 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,616 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.saml.saml2.binding.security.impl.SAML2HTTPPostSimpleSignSecurityHandler' on INBOUND message context
2017-07-19 22:19:02,619 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,620 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:154] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.messaging.handler.impl.CheckMandatoryIssuer' on INBOUND message context
2017-07-19 22:19:02,620 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.AuthnRequestImpl'
2017-07-19 22:19:02,621 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.WriteProfileInterceptorResultToStorage:68] - Profile Action WriteProfileInterceptorResultToStorage: No results available from interceptor context, nothing to store
2017-07-19 22:19:02,622 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.FilterFlowsByNonBrowserSupport:52] - Profile Action FilterFlowsByNonBrowserSupport: Request does not have non-browser requirement, nothing to do
2017-07-19 22:19:02,622 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:65] - Profile Action SelectProfileInterceptorFlow: Moving completed flow intercept/security-policy/saml2-sso to completed set, selecting next one
2017-07-19 22:19:02,623 - DEBUG [net.shibboleth.idp.profile.interceptor.impl.SelectProfileInterceptorFlow:80] - Profile Action SelectProfileInterceptorFlow: No flows available to choose from
2017-07-19 22:19:02,623 - DEBUG [net.shibboleth.idp.saml.profile.impl.InitializeOutboundMessageContext:149] - Profile Action InitializeOutboundMessageContext: Initialized outbound message context
2017-07-19 22:19:02,625 - DEBUG [net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:369] - Profile Action PopulateBindingAndEndpointContexts: Attempting to resolve endpoint of type {urn:oasis:names:tc:SAML:2.0:metadata}AssertionConsumerService for outbound message
2017-07-19 22:19:02,627 - DEBUG [net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:507] - Profile Action PopulateBindingAndEndpointContexts: Populating template endpoint for resolution from SAML AuthnRequest
2017-07-19 22:19:02,627 - DEBUG [net.shibboleth.idp.saml.profile.impl.PopulateBindingAndEndpointContexts:411] - Profile Action PopulateBindingAndEndpointContexts: Resolved endpoint at location https://blah.webex.com/dispatcher/SAML2AuthService?siteurl=blah using binding urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST
2017-07-19 22:19:02,628 - DEBUG [net.shibboleth.idp.saml.saml2.profile.delegation.impl.PopulateDelegationContext:392] - No AttributeConsumingService was resolved, won't be able to determine delegation requested status via metadata
2017-07-19 22:19:02,629 - DEBUG [net.shibboleth.idp.saml.saml2.profile.delegation.impl.PopulateDelegationContext:525] - No AttributeConsumingService was available
2017-07-19 22:19:02,629 - DEBUG [net.shibboleth.idp.saml.saml2.profile.delegation.impl.PopulateDelegationContext:510] - Delegation request was not explicitly indicated, using default value: NOT_REQUESTED
2017-07-19 22:19:02,630 - DEBUG [net.shibboleth.idp.saml.saml2.profile.delegation.impl.PopulateDelegationContext:294] - Issuance of a delegated Assertion is not in effect, skipping further processing
2017-07-19 22:19:02,633 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.PopulateEncryptionParameters:298] - Profile Action PopulateEncryptionParameters: No encryption requested, nothing to do
2017-07-19 22:19:02,637 - DEBUG [net.shibboleth.idp.saml.profile.impl.ExtractSubjectFromRequest:144] - Profile Action ExtractSubjectFromRequest: No Subject NameID/NameIdentifier in message needs inbound processing
2017-07-19 22:19:02,644 - DEBUG [net.shibboleth.idp.saml.profile.impl.InitializeAuthenticationContext:115] - Profile Action InitializeAuthenticationContext: Created authentication context: AuthenticationContext{initiationInstant=2017-07-19T22:19:02.644Z, isPassive=false, forceAuthn=false, hintedName=null, potentialFlows=[], activeResults=[], attemptedFlow=null, signaledFlowId=null, authenticationStateMap={}, resultCacheable=true, initialAuthenticationResult=null, authenticationResult=null, completionInstant=1970-01-01T00:00:00.000Z}
2017-07-19 22:19:02,645 - DEBUG [net.shibboleth.idp.authn.impl.InitializeRequestedPrincipalContext:111] - Profile Action InitializeRequestedPrincipalContext: Profile configuration does not include any default authentication methods
2017-07-19 22:19:02,646 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.ProcessRequestedAuthnContext:146] - Profile Action ProcessRequestedAuthnContext: AuthnRequest did not contain a RequestedAuthnContext, nothing to do
2017-07-19 22:19:02,649 - DEBUG [net.shibboleth.idp.authn.impl.PopulateAuthenticationContext:126] - Profile Action PopulateAuthenticationContext: Installing custom PrincipalEvalPredicateFactoryRegistry into AuthenticationContext
2017-07-19 22:19:02,650 - DEBUG [net.shibboleth.idp.authn.impl.PopulateAuthenticationContext:167] - Profile Action PopulateAuthenticationContext: Installed 1 authentication flows into AuthenticationContext
2017-07-19 22:19:02,651 - DEBUG [net.shibboleth.idp.session.impl.PopulateSessionContext:131] - Profile Action PopulateSessionContext: No session found for client
2017-07-19 22:19:02,652 - DEBUG [net.shibboleth.idp.authn.impl.FilterFlowsByForcedAuthn:53] - Profile Action FilterFlowsByForcedAuthn: Request does not have forced authentication requirement, nothing to do
2017-07-19 22:19:02,653 - DEBUG [net.shibboleth.idp.authn.impl.FilterFlowsByPassivity:53] - Profile Action FilterFlowsByPassivity: Request does not have passive requirement, nothing to do
2017-07-19 22:19:02,654 - DEBUG [net.shibboleth.idp.authn.impl.FilterFlowsByNonBrowserSupport:53] - Profile Action FilterFlowsByNonBrowserSupport: Request does not have non-browser requirement, nothing to do
2017-07-19 22:19:02,656 - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:257] - Profile Action SelectAuthenticationFlow: No specific Principals requested
2017-07-19 22:19:02,656 - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:292] - Profile Action SelectAuthenticationFlow: No usable active results available, selecting an inactive flow
2017-07-19 22:19:02,657 - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:334] - Profile Action SelectAuthenticationFlow: Selecting inactive authentication flow authn/RemoteUser
2017-07-19 22:19:03,271 - INFO [org.gluu.oxauth.client.authentication.AuthenticationFilter:51] - Property [oxauth.authorize.url] loaded from oxTrust.properties
2017-07-19 22:19:03,271 - INFO [org.gluu.oxauth.client.authentication.AuthenticationFilter:51] - Property [oxauth.client.id] loaded from oxTrust.properties
2017-07-19 22:19:03,271 - INFO [org.gluu.oxauth.client.authentication.AuthenticationFilter:51] - Property [oxauth.client.scope] loaded from oxTrust.properties
2017-07-19 22:19:27,854 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:51] - Property [oxauth.authorize.url] loaded from oxTrust.properties
2017-07-19 22:19:27,855 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:51] - Property [oxauth.token.url] loaded from oxTrust.properties
2017-07-19 22:19:27,855 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:51] - Property [oxauth.token.validation.url] loaded from oxTrust.properties
2017-07-19 22:19:27,855 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:51] - Property [oxauth.userinfo.url] loaded from oxTrust.properties
2017-07-19 22:19:27,856 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:51] - Property [oxauth.client.id] loaded from oxTrust.properties
2017-07-19 22:19:27,856 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:51] - Property [oxauth.client.password] loaded from oxTrust.properties
2017-07-19 22:19:28,108 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:151] - validate check session status:200
2017-07-19 22:19:28,108 - INFO [org.gluu.oxauth.client.validation.OAuthValidationFilter:157] - Session validation successful. User is logged in
2017-07-19 22:19:28,218 - DEBUG [net.shibboleth.idp.authn.impl.RemoteUserAuthServlet:231] - User identity extracted from REMOTE_USER: UserNameRemoved
2017-07-19 22:19:28,556 - INFO [net.shibboleth.idp.authn.impl.ValidateExternalAuthentication:115] - Profile Action ValidateExternalAuthentication: External authentication succeeded for user: UserNameRemoved
2017-07-19 22:19:28,557 - DEBUG [net.shibboleth.idp.authn.AbstractValidationAction:311] - Profile Action ValidateExternalAuthentication: Adding custom Principal(s) defined on underlying flow descriptor
2017-07-19 22:19:28,647 - DEBUG [net.shibboleth.idp.authn.impl.PopulateSubjectCanonicalizationContext:79] - Profile Action PopulateSubjectCanonicalizationContext: Installing 2 canonicalization flows into SubjectCanonicalizationContext
2017-07-19 22:19:28,650 - DEBUG [net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:100] - Profile Action SelectSubjectCanonicalizationFlow: Checking canonicalization flow c14n/x500 for applicability...
2017-07-19 22:19:28,651 - DEBUG [net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:106] - Profile Action SelectSubjectCanonicalizationFlow: Canonicalization flow c14n/x500 was not applicable to this request
2017-07-19 22:19:28,651 - DEBUG [net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:100] - Profile Action SelectSubjectCanonicalizationFlow: Checking canonicalization flow c14n/simple for applicability...
2017-07-19 22:19:28,652 - DEBUG [net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:83] - Profile Action SelectSubjectCanonicalizationFlow: Selecting canonicalization flow c14n/simple
2017-07-19 22:19:28,692 - DEBUG [net.shibboleth.idp.authn.AbstractSubjectCanonicalizationAction:226] - Profile Action SimpleSubjectCanonicalization: trimming whitespace of input string 'UserNameRemoved'
2017-07-19 22:19:28,697 - DEBUG [net.shibboleth.idp.session.impl.DetectIdentitySwitch:148] - Profile Action DetectIdentitySwitch: No previous session found, nothing to do
2017-07-19 22:19:28,701 - DEBUG [net.shibboleth.idp.authn.impl.FinalizeAuthentication:137] - Profile Action FinalizeAuthentication: Canonical principal name was established as 'UserNameRemoved'
2017-07-19 22:19:28,702 - DEBUG [net.shibboleth.idp.authn.impl.FinalizeAuthentication:186] - Profile Action FinalizeAuthentication: Request did not have explicit authentication requirements, result is accepted
2017-07-19 22:19:28,706 - DEBUG [net.shibboleth.idp.session.impl.UpdateSessionWithAuthenticationResult:221] - Profile Action UpdateSessionWithAuthenticationResult: Creating new session for principal UserNameRemoved
2017-07-19 22:19:28,718 - DEBUG [net.shibboleth.idp.session.impl.StorageBackedSessionManager:533] - Created new session df882787e032a9ebfb34ddb04343e868c4fc61119a9d623de6b8a971e2a70ce4 for principal UserNameRemoved
2017-07-19 22:19:28,719 - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:561] - Saving AuthenticationResult for flow authn/RemoteUser in session df882787e032a9ebfb34ddb04343e868c4fc61119a9d623de6b8a971e2a70ce4
2017-07-19 22:19:28,743 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:183] - Attribute Resolver 'ShibbolethAttributeResolver': Initiating attribute resolution
2017-07-19 22:19:28,755 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:191] - Attribute Resolver 'ShibbolethAttributeResolver': Attempting to resolve the following attribute definitions [uid, webexnameid, mail, lastnamewebex, firstnamewebex, uidwebex, emailwebex]
2017-07-19 22:19:28,756 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'uid'
2017-07-19 22:19:28,756 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:329] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving data connector siteLDAP
2017-07-19 22:19:28,772 - DEBUG [net.shibboleth.idp.attribute.resolver.dc.ldap.impl.TemplatedExecutableSearchFilterBuilder:212] - Template text (uid=$requestContext.principalName) yields (uid=UserNameRemoved)
2017-07-19 22:19:28,898 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:139] - Data Connector 'siteLDAP': produced the following 13 attributes during resolution [mail, objectClass, cn, inum, gluuSLAManager, uid, oxLastLogonTime, gluuStatus, oxCreationTimestamp, sn, memberOf, entryDN, updatedAt]
2017-07-19 22:19:28,898 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'mail': Values '[StringAttributeValue{value=daemien.boyes@blah.com.au}]'
2017-07-19 22:19:28,899 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'objectClass': Values '[StringAttributeValue{value=top}, StringAttributeValue{value=gluuPerson}]'
2017-07-19 22:19:28,899 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'cn': Values '[StringAttributeValue{value=Daemien Boyes}]'
2017-07-19 22:19:28,900 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'inum': Values '[StringAttributeValue{value=@!A792.8560.4498.9707!0001!729A.C307!0000!34D2.317D}]'
2017-07-19 22:19:28,908 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'gluuSLAManager': Values '[StringAttributeValue{value=true}]'
2017-07-19 22:19:28,909 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'uid': Values '[StringAttributeValue{value=UserNameRemoved}]'
2017-07-19 22:19:28,910 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'oxLastLogonTime': Values '[StringAttributeValue{value=20170719221925.188Z}]'
2017-07-19 22:19:28,914 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'gluuStatus': Values '[StringAttributeValue{value=active}]'
2017-07-19 22:19:28,914 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'oxCreationTimestamp': Values '[StringAttributeValue{value=20170719195334.606Z}]'
2017-07-19 22:19:28,915 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'sn': Values '[StringAttributeValue{value=Boyes}]'
2017-07-19 22:19:28,915 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'memberOf': Values '[StringAttributeValue{value=inum=@!A792.8560.4498.9707!0001!729A.C307!0003!60B7,ou=groups,o=@!A792.8560.4498.9707!0001!729A.C307,o=gluu}]'
2017-07-19 22:19:28,916 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'entryDN': Values '[StringAttributeValue{value=inum=@!A792.8560.4498.9707!0001!729A.C307!0000!34D2.317D,ou=people,o=@!A792.8560.4498.9707!0001!729A.C307,o=gluu}]'
2017-07-19 22:19:28,916 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractDataConnector:143] - Data Connector 'siteLDAP': Attribute 'updatedAt': Values '[StringAttributeValue{value=20170719195514.187Z}]'
2017-07-19 22:19:28,917 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:347] - Attribute Resolver 'ShibbolethAttributeResolver': Data connector 'siteLDAP' resolved the following attributes: [mail, objectClass, cn, inum, gluuSLAManager, uid, oxLastLogonTime, gluuStatus, oxCreationTimestamp, sn, memberOf, entryDN, updatedAt]
2017-07-19 22:19:28,918 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'uid'
2017-07-19 22:19:28,919 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:247] - Attribute Definition 'uid': produced an attribute with the following values [StringAttributeValue{value=UserNameRemoved}]
2017-07-19 22:19:28,920 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'uid' produced an attribute with 1 values
2017-07-19 22:19:28,921 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'webexnameid'
2017-07-19 22:19:28,922 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'webexnameid'
2017-07-19 22:19:28,922 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:247] - Attribute Definition 'webexnameid': produced an attribute with the following values [StringAttributeValue{value=daemien.boyes@blah.com.au}]
2017-07-19 22:19:28,923 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'webexnameid' produced an attribute with 1 values
2017-07-19 22:19:28,923 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'mail'
2017-07-19 22:19:28,924 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'mail'
2017-07-19 22:19:28,924 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:247] - Attribute Definition 'mail': produced an attribute with the following values [StringAttributeValue{value=daemien.boyes@blah.com.au}]
2017-07-19 22:19:28,925 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'mail' produced an attribute with 1 values
2017-07-19 22:19:28,925 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'lastnamewebex'
2017-07-19 22:19:28,925 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'lastnamewebex'
2017-07-19 22:19:28,926 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:245] - Attribute Definition 'lastnamewebex': produced an attribute with no values
2017-07-19 22:19:28,927 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'lastnamewebex' produced an attribute with 0 values
2017-07-19 22:19:28,931 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'firstnamewebex'
2017-07-19 22:19:28,932 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'firstnamewebex'
2017-07-19 22:19:28,935 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:245] - Attribute Definition 'firstnamewebex': produced an attribute with no values
2017-07-19 22:19:28,935 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'firstnamewebex' produced an attribute with 0 values
2017-07-19 22:19:28,936 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'uidwebex'
2017-07-19 22:19:28,936 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'uidwebex'
2017-07-19 22:19:28,936 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:245] - Attribute Definition 'uidwebex': produced an attribute with no values
2017-07-19 22:19:28,937 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'uidwebex' produced an attribute with 0 values
2017-07-19 22:19:28,937 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:372] - Attribute Resolver 'ShibbolethAttributeResolver': Resolving dependencies for 'emailwebex'
2017-07-19 22:19:28,938 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:388] - Attribute Resolver 'ShibbolethAttributeResolver': Finished resolving dependencies for 'emailwebex'
2017-07-19 22:19:28,938 - DEBUG [net.shibboleth.idp.attribute.resolver.AbstractAttributeDefinition:245] - Attribute Definition 'emailwebex': produced an attribute with no values
2017-07-19 22:19:28,939 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:272] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute definition 'emailwebex' produced an attribute with 0 values
2017-07-19 22:19:28,940 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:201] - Attribute Resolver 'ShibbolethAttributeResolver': Finalizing resolved attributes
2017-07-19 22:19:28,940 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:434] - Attribute Resolver 'ShibbolethAttributeResolver': De-duping attribute definition uid result
2017-07-19 22:19:28,941 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:446] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute 'uid' has 1 values after post-processing
2017-07-19 22:19:28,941 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:434] - Attribute Resolver 'ShibbolethAttributeResolver': De-duping attribute definition webexnameid result
2017-07-19 22:19:28,942 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:446] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute 'webexnameid' has 1 values after post-processing
2017-07-19 22:19:28,942 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:434] - Attribute Resolver 'ShibbolethAttributeResolver': De-duping attribute definition mail result
2017-07-19 22:19:28,943 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:446] - Attribute Resolver 'ShibbolethAttributeResolver': Attribute 'mail' has 1 values after post-processing
2017-07-19 22:19:28,943 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:428] - Attribute Resolver 'ShibbolethAttributeResolver': Removing result of attribute definition 'lastnamewebex', contains no values
2017-07-19 22:19:28,944 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:428] - Attribute Resolver 'ShibbolethAttributeResolver': Removing result of attribute definition 'firstnamewebex', contains no values
2017-07-19 22:19:28,944 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:428] - Attribute Resolver 'ShibbolethAttributeResolver': Removing result of attribute definition 'uidwebex', contains no values
2017-07-19 22:19:28,944 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:428] - Attribute Resolver 'ShibbolethAttributeResolver': Removing result of attribute definition 'emailwebex', contains no values
2017-07-19 22:19:28,945 - DEBUG [net.shibboleth.idp.attribute.resolver.impl.AttributeResolverImpl:206] - Attribute Resolver 'ShibbolethAttributeResolver': Final resolved attribute collection: [webexnameid, uid, mail]
2017-07-19 22:19:28,952 - DEBUG [net.shibboleth.idp.attribute.filter.impl.AttributeFilterImpl:108] - Attribute filtering engine 'ShibbolethAttributeFilter' Beginning process of filtering the following 3 attributes: [mail, webexnameid, uid]
2017-07-19 22:19:28,952 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeFilterPolicy:125] - Attribute Filter Policy 'SiteApp1' Checking if attribute filter policy is active
2017-07-19 22:19:28,953 - DEBUG [net.shibboleth.idp.attribute.filter.policyrule.filtercontext.impl.AttributeRequesterPolicyRule:54] - Attribute Filter '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/PolicyRequirementRule:_883c6e83acc7cc647de05601e3d5890a': Found attribute requester: https://blah.webex.com
2017-07-19 22:19:28,953 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeFilterPolicy:132] - Attribute Filter Policy 'SiteApp1' Policy is active for this request
2017-07-19 22:19:28,954 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeFilterPolicy:159] - Attribute Filter Policy 'SiteApp1' Applying attribute filter policy to current set of attributes: [mail, webexnameid, uid]
2017-07-19 22:19:28,955 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeRule:168] - Attribute filtering engine '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/AttributeRule:_80d83c86584c15966b66029d4bb6ec06' Filtering values for attribute 'uid' which currently contains 1 values
2017-07-19 22:19:28,955 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeRule:177] - Attribute filtering engine '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/AttributeRule:_80d83c86584c15966b66029d4bb6ec06' Filter has permitted the release of 1 values for attribute 'uid'
2017-07-19 22:19:28,956 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeRule:168] - Attribute filtering engine '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/AttributeRule:_d861c9aab068cee4e5aef0250b7be2ef' Filtering values for attribute 'webexnameid' which currently contains 1 values
2017-07-19 22:19:28,956 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeRule:177] - Attribute filtering engine '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/AttributeRule:_d861c9aab068cee4e5aef0250b7be2ef' Filter has permitted the release of 1 values for attribute 'webexnameid'
2017-07-19 22:19:28,957 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeRule:168] - Attribute filtering engine '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/AttributeRule:_bdcbf11f99e13523c019c012cfa6095a' Filtering values for attribute 'mail' which currently contains 1 values
2017-07-19 22:19:28,957 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeRule:177] - Attribute filtering engine '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/AttributeRule:_bdcbf11f99e13523c019c012cfa6095a' Filter has permitted the release of 1 values for attribute 'mail'
2017-07-19 22:19:28,958 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeFilterPolicy:125] - Attribute Filter Policy 'SiteApp2' Checking if attribute filter policy is active
2017-07-19 22:19:28,958 - DEBUG [net.shibboleth.idp.attribute.filter.policyrule.filtercontext.impl.AttributeRequesterPolicyRule:54] - Attribute Filter '/AttributeFilterPolicyGroup:ShibbolethFilterPolicy/PolicyRequirementRule:_6e4f42c18db25c53778095650cba5ff7': Found attribute requester: https://blah.webex.com
2017-07-19 22:19:28,958 - DEBUG [net.shibboleth.idp.attribute.filter.AttributeFilterPolicy:134] - Attribute Filter Policy 'SiteApp2' Policy is not active for this request
2017-07-19 22:19:28,959 - DEBUG [net.shibboleth.idp.attribute.filter.impl.AttributeFilterImpl:167] - Attribute filtering engine 'ShibbolethAttributeFilter': 1 values for attribute 'mail' remained after filtering
2017-07-19 22:19:28,959 - DEBUG [net.shibboleth.idp.attribute.filter.impl.AttributeFilterImpl:167] - Attribute filtering engine 'ShibbolethAttributeFilter': 1 values for attribute 'webexnameid' remained after filtering
2017-07-19 22:19:28,960 - DEBUG [net.shibboleth.idp.attribute.filter.impl.AttributeFilterImpl:167] - Attribute filtering engine 'ShibbolethAttributeFilter': 1 values for attribute 'uid' remained after filtering
2017-07-19 22:19:29,016 - DEBUG [net.shibboleth.idp.saml.profile.impl.BaseAddAuthenticationStatementToAssertion:170] - Profile Action AddAuthnStatementToAssertion: Attempting to add an AuthenticationStatement to outgoing Assertion
2017-07-19 22:19:29,025 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAuthnStatementToAssertion:165] - Profile Action AddAuthnStatementToAssertion: Added AuthenticationStatement to Assertion _5c887090f2856240f2d12841ecad36a8
2017-07-19 22:19:29,043 - DEBUG [net.shibboleth.idp.saml.profile.impl.BaseAddAttributeStatementToAssertion:229] - Profile Action AddAttributeStatementToAssertion: Attempting to add an AttributeStatement to outgoing Assertion
2017-07-19 22:19:29,043 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:174] - Profile Action AddAttributeStatementToAssertion: Attempting to encode attribute webexnameid as a SAML 2 Attribute
2017-07-19 22:19:29,044 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:204] - Profile Action AddAttributeStatementToAssertion: Attribute webexnameid did not have a usable SAML 2 Attribute encoder associated with it, nothing to do
2017-07-19 22:19:29,044 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:174] - Profile Action AddAttributeStatementToAssertion: Attempting to encode attribute uid as a SAML 2 Attribute
2017-07-19 22:19:29,045 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:188] - Profile Action AddAttributeStatementToAssertion: Encoding attribute uid as a SAML 2 Attribute
2017-07-19 22:19:29,045 - DEBUG [net.shibboleth.idp.saml.attribute.encoding.AbstractSAMLAttributeEncoder:154] - Beginning to encode attribute uid
2017-07-19 22:19:29,047 - DEBUG [net.shibboleth.idp.saml.attribute.encoding.SAMLEncoderSupport:73] - Encoding value UserNameRemoved of attribute uid
2017-07-19 22:19:29,049 - DEBUG [net.shibboleth.idp.saml.attribute.encoding.AbstractSAMLAttributeEncoder:191] - Completed encoding 1 values for attribute uid
2017-07-19 22:19:29,051 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:174] - Profile Action AddAttributeStatementToAssertion: Attempting to encode attribute mail as a SAML 2 Attribute
2017-07-19 22:19:29,051 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:188] - Profile Action AddAttributeStatementToAssertion: Encoding attribute mail as a SAML 2 Attribute
2017-07-19 22:19:29,052 - DEBUG [net.shibboleth.idp.saml.attribute.encoding.AbstractSAMLAttributeEncoder:154] - Beginning to encode attribute mail
2017-07-19 22:19:29,052 - DEBUG [net.shibboleth.idp.saml.attribute.encoding.SAMLEncoderSupport:73] - Encoding value daemien.boyes@blah.com.au of attribute mail
2017-07-19 22:19:29,053 - DEBUG [net.shibboleth.idp.saml.attribute.encoding.AbstractSAMLAttributeEncoder:191] - Completed encoding 1 values for attribute mail
2017-07-19 22:19:29,054 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.AddAttributeStatementToAssertion:118] - Profile Action AddAttributeStatementToAssertion: Adding constructed AttributeStatement to Assertion _5c887090f2856240f2d12841ecad36a8
2017-07-19 22:19:29,079 - DEBUG [net.shibboleth.idp.saml.profile.logic.DefaultNameIdentifierFormatStrategy:100] - Configuration specifies the following formats: []
2017-07-19 22:19:29,079 - DEBUG [net.shibboleth.idp.saml.profile.logic.DefaultNameIdentifierFormatStrategy:113] - Configuration did not specify any formats, relying on metadata alone
2017-07-19 22:19:29,080 - DEBUG [net.shibboleth.idp.saml.nameid.impl.AttributeSourcedSAML2NameIDGenerator:197] - Checking for source attribute webexnameid
2017-07-19 22:19:29,081 - DEBUG [net.shibboleth.idp.saml.nameid.impl.AttributeSourcedSAML2NameIDGenerator:216] - Generating NameID from String-valued attribute webexnameid
2017-07-19 22:19:29,138 - DEBUG [net.shibboleth.idp.saml.saml2.profile.delegation.impl.DecorateDelegatedAssertion:585] - Found Assertion with AuthnStatement to decorate in outbound Response
2017-07-19 22:19:29,139 - DEBUG [net.shibboleth.idp.saml.saml2.profile.delegation.impl.DecorateDelegatedAssertion:288] - Issuance of delegated was not indicated, skipping assertion decoration
2017-07-19 22:19:29,390 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:159] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler of type 'org.opensaml.messaging.handler.impl.BasicMessageHandlerChain' on OUTBOUND message context
2017-07-19 22:19:29,391 - DEBUG [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:175] - Profile Action WebFlowMessageHandlerAdaptor: Invoking message handler on message context containing a message of type 'org.opensaml.saml.saml2.core.impl.ResponseImpl'
2017-07-19 22:19:29,415 - DEBUG [net.shibboleth.idp.saml.profile.impl.SpringAwareMessageEncoderFactory:100] - Looking up message encoder based on binding URI: urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST
2017-07-19 22:19:29,456 - DEBUG [net.shibboleth.idp.profile.impl.RecordResponseComplete:89] - Profile Action RecordResponseComplete: Record response complete
2017-07-19 22:19:29,464 - INFO [Shibboleth-Audit.SSO:241] - 20170719T221929Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|s2ecc78c3f01e5edcb73a00fabf9871136e06fa866|https://blah.webex.com|http://shibboleth.net/ns/profiles/saml2/sso/browser|https://sso.blah.net/idp/shibboleth|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_ceec9343c4bf025d329afbc6364d448d|UserNameRemoved|urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport|webexnameid,uid,mail|user.name@blah.com|_5c887090f2856240f2d12841ecad36a8|