idp login issue connecting to ldap
Jason Separovic
jseppa01 at gmail.com
Mon Aug 3 17:08:04 EDT 2015
2015-08-03 14:00:05,309 - DEBUG
[org.springframework.webflow.mvc.servlet.FlowHandlerMapping:108] - Mapping
request with URI '/idp/profile/SAML2/Redirect/SSO' to flow with id
'SAML2/Redirect/SSO'
2015-08-03 14:00:05,309 - DEBUG
[org.springframework.webflow.executor.FlowExecutorImpl:161] - Resuming flow
execution with key 'e1s1
2015-08-03 14:00:05,309 - DEBUG
[org.springframework.webflow.conversation.impl.SessionBindingConversationMan
ager:75] - Locking conversation 1
2015-08-03 14:00:05,309 - DEBUG
[org.springframework.webflow.execution.repository.impl.DefaultFlowExecutionR
epository:106] - Getting flow execution with key 'e1s1'
2015-08-03 14:00:05,309 - DEBUG
[org.springframework.webflow.definition.registry.FlowDefinitionRegistryImpl:
58] - Getting FlowDefinition with id 'SAML2/Redirect/SSO'
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.definition.registry.FlowDefinitionRegistryImpl:
58] - Getting FlowDefinition with id 'authn-initial'
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.definition.registry.FlowDefinitionRegistryImpl:
58] - Getting FlowDefinition with id 'authn/Password'
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.engine.impl.FlowExecutionImpl:250] - Resuming
in org.springframework.webflow.mvc.servlet.MvcExternalContext at 2cc6fc27
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.engine.ViewState:286] - Rendering +
[ServletMvcView at 701d0ed2 view =
org.springframework.web.servlet.view.velocity.VelocityView: name 'login';
URL [login.vm]]
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.engine.ViewState:287] - Flash scope =
map[[empty]]
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.engine.ViewState:288] - Messages =
[DefaultMessageContext at 683b6426 sourceMessages = map[[null] ->
list[[empty]]]]
2015-08-03 14:00:05,310 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 4c9f5430 expression = environment, resultExpression =
viewScope.environment]
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 4c9f5430 expression = environment,
resultExpression = viewScope.environment]; result = success
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 6c184731 expression = opensamlProfileRequestContext,
resultExpression = viewScope.profileRequestContext]
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,311 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 6c184731 expression =
opensamlProfileRequestContext, resultExpression =
viewScope.profileRequestContext]; result = success
2015-08-03 14:00:05,312 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 4ec7abf8 expression =
opensamlProfileRequestContext.getSubcontext(T(net.shibboleth.idp.authn.conte
xt.AuthenticationContext)), resultExpression =
viewScope.authenticationContext]
2015-08-03 14:00:05,314 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,316 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,317 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 4ec7abf8 expression =
opensamlProfileRequestContext.getSubcontext(T(net.shibboleth.idp.authn.conte
xt.AuthenticationContext)), resultExpression =
viewScope.authenticationContext]; result = success
2015-08-03 14:00:05,317 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 131ca47f expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.ui.context.RelyingP
artyUIContext)), resultExpression = viewScope.rpUIContext]
2015-08-03 14:00:05,317 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,318 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,318 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 131ca47f expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.ui.context.RelyingP
artyUIContext)), resultExpression = viewScope.rpUIContext]; result = success
2015-08-03 14:00:05,318 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 25944cf8 expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.authn.context.Authe
nticationErrorContext)), resultExpression =
viewScope.authenticationErrorContext]
2015-08-03 14:00:05,318 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,319 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,319 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 25944cf8 expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.authn.context.Authe
nticationErrorContext)), resultExpression =
viewScope.authenticationErrorContext]; result = success
2015-08-03 14:00:05,319 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 9cd56da expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.authn.context.Authe
nticationWarningContext)), resultExpression =
viewScope.authenticationWarningContext]
2015-08-03 14:00:05,319 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,320 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,320 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 9cd56da expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.authn.context.Authe
nticationWarningContext)), resultExpression =
viewScope.authenticationWarningContext]; result = success
2015-08-03 14:00:05,320 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 138bda5 expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.authn.context.LDAPR
esponseContext)), resultExpression = viewScope.ldapResponseContext]
2015-08-03 14:00:05,320 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,320 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 138bda5 expression =
authenticationContext.getSubcontext(T(net.shibboleth.idp.authn.context.LDAPR
esponseContext)), resultExpression = viewScope.ldapResponseContext]; result
= success
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 1af151d4 expression =
T(net.shibboleth.utilities.java.support.codec.HTMLEncoder), resultExpression
= viewScope.encoder]
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 1af151d4 expression =
T(net.shibboleth.utilities.java.support.codec.HTMLEncoder), resultExpression
= viewScope.encoder]; result = success
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 3c6e3212 expression =
flowRequestContext.getExternalContext().getNativeRequest(), resultExpression
= viewScope.request]
2015-08-03 14:00:05,321 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,322 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,322 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 3c6e3212 expression =
flowRequestContext.getExternalContext().getNativeRequest(), resultExpression
= viewScope.request]; result = success
2015-08-03 14:00:05,322 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:49] - Executing
[EvaluateAction at 2c81abba expression =
flowRequestContext.getExternalContext().getNativeResponse(),
resultExpression = viewScope.response]
2015-08-03 14:00:05,322 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:142] - Putting action
execution attributes map[[empty]]
2015-08-03 14:00:05,322 - DEBUG
[org.springframework.webflow.execution.AnnotatedAction:149] - Clearing
action execution attributes map[[empty]]
2015-08-03 14:00:05,322 - DEBUG
[org.springframework.webflow.execution.ActionExecutor:53] - Finished
executing [EvaluateAction at 2c81abba expression =
flowRequestContext.getExternalContext().getNativeResponse(),
resultExpression = viewScope.response]; result = success
2015-08-03 14:00:05,323 - DEBUG
[org.springframework.webflow.mvc.view.AbstractMvcView:194] - Rendering MVC
[org.springframework.web.servlet.view.velocity.VelocityView: name 'login';
URL [login.vm]] with model map [{authenticationErrorContext=null,
request=(POST
https://sso.jseppa.com/idp/profile/SAML2/Redirect/SSO?execution=e1s1)@437287
479 org.eclipse.jetty.server.Request at 1a107a37, ldapResponseContext=null,
viewScope=map['authenticationErrorContext' -> [null], 'request' -> (POST
https://sso.jseppa.com/idp/profile/SAML2/Redirect/SSO?execution=e1s1)@437287
479 org.eclipse.jetty.server.Request at 1a107a37, 'environment' ->
StandardServletEnvironment {activeProfiles=[], defaultProfiles=[default],
propertySources=[servletConfigInitParams,servletContextInitParams,jndiProper
ties,systemProperties,systemEnvironment,file
[/opt/shibboleth-idp/conf/idp.properties]]}, 'ldapResponseContext' ->
[null], 'authenticationContext' ->
AuthenticationContext{initiationInstant=2015-08-03T13:59:48.948-07:00,
isPassive=false, forceAuthn=false, hintedName=null,
potentialFlows=[authn/Password], activeResults=[],
attemptedFlow=AuthenticationFlowDescriptor{flowId=authn/Password,
supportsPassive=true, supportsForcedAuthentication=true, lifetime=3600000,
inactivityTimeout=1800000}, signaledFlowId=null, resultCacheable=true,
completionInstant=1969-12-31T16:00:00.000-08:00}, 'profileRequestContext' ->
org.opensaml.profile.context.ProfileRequestContext at af9a742, 'response' ->
org.opensaml.storage.impl.ServletRequestScopedStorageService$OutputIntercept
ingHttpServletResponseProxy at 7f508b39, 'authenticationWarningContext' ->
[null], 'rpUIContext' ->
net.shibboleth.idp.ui.context.RelyingPartyUIContext at 4292dbf1, 'encoder' ->
HTMLEncoder],
authenticationContext=AuthenticationContext{initiationInstant=2015-08-03T13:
59:48.948-07:00, isPassive=false, forceAuthn=false, hintedName=null,
potentialFlows=[authn/Password], activeResults=[],
attemptedFlow=AuthenticationFlowDescriptor{flowId=authn/Password,
supportsPassive=true, supportsForcedAuthentication=true, lifetime=3600000,
inactivityTimeout=1800000}, signaledFlowId=null, resultCacheable=true,
completionInstant=1969-12-31T16:00:00.000-08:00},
flowExecutionUrl=/idp/profile/SAML2/Redirect/SSO?execution=e1s1,
authenticationWarningContext=null,
rpUIContext=net.shibboleth.idp.ui.context.RelyingPartyUIContext at 4292dbf1,
flowRequestContext=[RequestControlContextImpl at 4c79daa1 externalContext =
org.springframework.webflow.mvc.servlet.MvcExternalContext at 2cc6fc27,
currentEvent = [null], requestScope = map[[empty]], attributes =
map[[empty]], messageContext = [DefaultMessageContext at 683b6426
sourceMessages = map[[null] -> list[[empty]]]], flowExecution =
[FlowExecutionImpl at f98608 flow = 'SAML2/Redirect/SSO', flowSessions =
list[[FlowSessionImpl at feacec0 flow = 'SAML2/Redirect/SSO', state =
'DoInitialAuthenticationSubflow', scope = map[[empty]]],
[FlowSessionImpl at 7cf30b90 flow = 'authn-initial', state =
'CallAuthenticationFlow', scope = map['calledAsSubflow' -> true]],
[FlowSessionImpl at 46fcb053 flow = 'authn/Password', state =
'DisplayUsernamePasswordPage', scope = map['calledAsSubflow' -> true,
'viewScope' -> map['authenticationErrorContext' -> [null], 'request' ->
(POST
https://sso.jseppa.com/idp/profile/SAML2/Redirect/SSO?execution=e1s1)@437287
479 org.eclipse.jetty.server.Request at 1a107a37, 'environment' ->
StandardServletEnvironment {activeProfiles=[], defaultProfiles=[default],
propertySources=[servletConfigInitParams,servletContextInitParams,jndiProper
ties,systemProperties,systemEnvironment,file
[/opt/shibboleth-idp/conf/idp.properties]]}, 'ldapResponseContext' ->
[null], 'authenticationContext' ->
AuthenticationContext{initiationInstant=2015-08-03T13:59:48.948-07:00,
isPassive=false, forceAuthn=false, hintedName=null,
potentialFlows=[authn/Password], activeResults=[],
attemptedFlow=AuthenticationFlowDescriptor{flowId=authn/Password,
supportsPassive=true, supportsForcedAuthentication=true, lifetime=3600000,
inactivityTimeout=1800000}, signaledFlowId=null, resultCacheable=true,
completionInstant=1969-12-31T16:00:00.000-08:00}, 'profileRequestContext' ->
org.opensaml.profile.context.ProfileRequestContext at af9a742, 'response' ->
org.opensaml.storage.impl.ServletRequestScopedStorageService$OutputIntercept
ingHttpServletResponseProxy at 7f508b39, 'authenticationWarningContext' ->
[null], 'rpUIContext' ->
net.shibboleth.idp.ui.context.RelyingPartyUIContext at 4292dbf1, 'encoder' ->
HTMLEncoder]]]]]], encoder=class
net.shibboleth.utilities.java.support.codec.HTMLEncoder,
calledAsSubflow=true, environment=StandardServletEnvironment
{activeProfiles=[], defaultProfiles=[default],
propertySources=[servletConfigInitParams,servletContextInitParams,jndiProper
ties,systemProperties,systemEnvironment,file
[/opt/shibboleth-idp/conf/idp.properties]]}, currentUser=null,
flowExecutionKey=e1s1,
profileRequestContext=org.opensaml.profile.context.ProfileRequestContext at af9
a742,
response=org.opensaml.storage.impl.ServletRequestScopedStorageService$Output
InterceptingHttpServletResponseProxy at 7f508b39,
opensamlProfileRequestContext=org.opensaml.profile.context.ProfileRequestCon
text at af9a742, flashScope=map[[empty]]}]
2015-08-03 14:00:05,327 - DEBUG
[org.springframework.webflow.execution.repository.impl.DefaultFlowExecutionR
epository:121] - Putting flow execution '[FlowExecutionImpl at f98608 flow =
'SAML2/Redirect/SSO', flowSessions = list[[FlowSessionImpl at feacec0 flow =
'SAML2/Redirect/SSO', state = 'DoInitialAuthenticationSubflow', scope =
map[[empty]]], [FlowSessionImpl at 7cf30b90 flow = 'authn-initial', state =
'CallAuthenticationFlow', scope = map['calledAsSubflow' -> true]],
[FlowSessionImpl at 46fcb053 flow = 'authn/Password', state =
'DisplayUsernamePasswordPage', scope = map['calledAsSubflow' -> true,
'viewScope' -> map['authenticationErrorContext' -> [null], 'request' ->
(POST
https://sso.jseppa.com/idp/profile/SAML2/Redirect/SSO?execution=e1s1)@437287
479 org.eclipse.jetty.server.Request at 1a107a37, 'environment' ->
StandardServletEnvironment {activeProfiles=[], defaultProfiles=[default],
propertySources=[servletConfigInitParams,servletContextInitParams,jndiProper
ties,systemProperties,systemEnvironment,file
[/opt/shibboleth-idp/conf/idp.properties]]}, 'ldapResponseContext' ->
[null], 'authenticationContext' ->
AuthenticationContext{initiationInstant=2015-08-03T13:59:48.948-07:00,
isPassive=false, forceAuthn=false, hintedName=null,
potentialFlows=[authn/Password], activeResults=[],
attemptedFlow=AuthenticationFlowDescriptor{flowId=authn/Password,
supportsPassive=true, supportsForcedAuthentication=true, lifetime=3600000,
inactivityTimeout=1800000}, signaledFlowId=null, resultCacheable=true,
completionInstant=1969-12-31T16:00:00.000-08:00}, 'profileRequestContext' ->
org.opensaml.profile.context.ProfileRequestContext at af9a742, 'response' ->
org.opensaml.storage.impl.ServletRequestScopedStorageService$OutputIntercept
ingHttpServletResponseProxy at 7f508b39, 'authenticationWarningContext' ->
[null], 'rpUIContext' ->
net.shibboleth.idp.ui.context.RelyingPartyUIContext at 4292dbf1, 'encoder' ->
HTMLEncoder]]]]]' into repository
2015-08-03 14:00:05,327 - DEBUG
[org.springframework.webflow.execution.repository.impl.DefaultFlowExecutionR
epository:128] - Adding snapshot to group with id 1
2015-08-03 14:00:05,327 - DEBUG
[org.springframework.webflow.conversation.impl.SessionBindingConversationMan
ager:86] - Putting conversation attribute 'scope' with value
map['opensamlProfileRequestContext' ->
org.opensaml.profile.context.ProfileRequestContext at af9a742, 'flashScope' ->
map['messagesMemento' -> map[[empty]]]]
2015-08-03 14:00:05,328 - DEBUG
[org.springframework.webflow.conversation.impl.SessionBindingConversationMan
ager:107] - Unlocking conversation 1
From: Tom Zeller <tzeller at dragonacea.biz>
Reply-To: Shib Users <users at shibboleth.net>
Date: Monday, August 3, 2015 at 2:04 PM
To: Shib Users <users at shibboleth.net>
Subject: Re: idp login issue connecting to ldap
On Mon, Aug 3, 2015 at 3:55 PM, Cantor, Scott <cantor.2 at osu.edu> wrote:
> I don't know that it would show anything, but the logging needed here would be
very low level, probably the org.springframework.webflow categories to start
with.
After submitting the login form and with org.springframework.webflow at
DEBUG, the next couple log lines should be something like :
DEBUG [org.springframework.webflow.mvc.servlet.FlowHandlerMapping:108] -
Mapping request with URI '/idp/profile/SAML2/POST/SSO' to flow with id
'SAML2/POST/SSO'
DEBUG [org.springframework.webflow.executor.FlowExecutorImpl:161] - Resuming
flow execution with key 'e1s1
-- To unsubscribe from this list send an email to
users-unsubscribe at shibboleth.net
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20150803/fb298bc4/attachment-0001.html>
More information about the users
mailing list