mmarchese Absent Member.
Absent Member.
2053 views

Timeout after login with Kerberos SSO

Hello all,

We are trying to set up Kerberos SSO within our Identity Applications (4.6.3) installation.

We generated the keytab file with a Windows 2012 KDC (AD Domain Controller).

Set up the krb5.conf and the Kerberos_login.config files as it's describe in the documentation.

Once we try to login to the User Application, we are not prompt for user and password (SSO seems to work) but we receive the following error:

Login session has timed out. Log in to the application again.
Click this link to login.

However, if we login from a workstation outside the AD domain, the fallback login prompts and we access without any problems with username and password.

The startup (kerberos), login and osp logs follows:

Startup (Kerberos):

Starting initialization of device 1d507dd2-bc90-4a31-a140-033abd871118 using server version: 6.1.6 2017-05-24T21:32:00Z
Pre: [OSP]
Lvl: INFO
Java: internal.osp.framework.servlet.OSPServletContext.logVersion() [198] thread=localhost-startStop-1
Time: 2018-10-09T16:14:51.951-0300
LogDta: OSP version: 6.1.6 2017-05-24T21:32:00Z

Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt true ticketCache is null isInitiator true KeyTab is /opt/netiq/idm/apps/kerberos/idmportal.keytab refreshKrb5Config is true principal is idmdesa@BF.ARG.IGRUPOBBVA tryFirstPass is false useFirstPass is false storePass is false clearPass is false
Refreshing Kerberos configuration
Java config name: /etc/krb5.conf
Loaded from Java config
>>> KdcAccessibility: reset
>>> KdcAccessibility: reset
>>> KeyTabInputStream, readName(): BF.ARG.IGRUPOBBVA
>>> KeyTabInputStream, readName(): idmdesa
>>> KeyTab: load() entry length: 51; type: 1
>>> KeyTabInputStream, readName(): BF.ARG.IGRUPOBBVA
>>> KeyTabInputStream, readName(): idmdesa
>>> KeyTab: load() entry length: 51; type: 3
>>> KeyTabInputStream, readName(): BF.ARG.IGRUPOBBVA
>>> KeyTabInputStream, readName(): idmdesa
>>> KeyTab: load() entry length: 59; type: 23
>>> KeyTabInputStream, readName(): BF.ARG.IGRUPOBBVA
>>> KeyTabInputStream, readName(): idmdesa
>>> KeyTab: load() entry length: 75; type: 18
>>> KeyTabInputStream, readName(): BF.ARG.IGRUPOBBVA
>>> KeyTabInputStream, readName(): idmdesa
>>> KeyTab: load() entry length: 59; type: 17
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
default etypes for default_tkt_enctypes: 18 23.
>>> KrbAsReq creating message
>>> KrbKdcReq send: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000, number of retries =3, #bytes=151
>>> KDCCommunication: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000,Attempt =1, #bytes=151
>>> KrbKdcReq send: #bytes read=202
>>>Pre-Authentication Data:
PA-DATA type = 19
PA-ETYPE-INFO2 etype = 18, salt = BF.ARG.IGRUPOBBVAidmdesa, s2kparams = null
PA-ETYPE-INFO2 etype = 23, salt = null, s2kparams = null

>>>Pre-Authentication Data:
PA-DATA type = 2
PA-ENC-TIMESTAMP
>>>Pre-Authentication Data:
PA-DATA type = 16

>>>Pre-Authentication Data:
PA-DATA type = 15

>>> KdcAccessibility: remove bbva-ad1.bf.arg.igrupobbva
>>> KDCRep: init() encoding tag is 126 req type is 11
>>>KRBError:
sTime is Tue Oct 09 16:14:54 ART 2018 1539112494000
suSec is 822277
error code is 25
error Message is Additional pre-authentication required
sname is krbtgt/BF.ARG.IGRUPOBBVA@BF.ARG.IGRUPOBBVA
eData provided.
msgType is 30
>>>Pre-Authentication Data:
PA-DATA type = 19
PA-ETYPE-INFO2 etype = 18, salt = BF.ARG.IGRUPOBBVAidmdesa, s2kparams = null
PA-ETYPE-INFO2 etype = 23, salt = null, s2kparams = null

>>>Pre-Authentication Data:
PA-DATA type = 2
PA-ENC-TIMESTAMP
>>>Pre-Authentication Data:
PA-DATA type = 16

>>>Pre-Authentication Data:
PA-DATA type = 15

KrbAsReqBuilder: PREAUTH FAILED/REQ, re-send AS-REQ
default etypes for default_tkt_enctypes: 18 23.
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
default etypes for default_tkt_enctypes: 18 23.
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
>>> KrbAsReq creating message
>>> KrbKdcReq send: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000, number of retries =3, #bytes=238
>>> KDCCommunication: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000,Attempt =1, #bytes=238
>>> KrbKdcReq send: #bytes read=106
>>> KrbKdcReq send: kdc=bbva-ad1.bf.arg.igrupobbva TCP:88, timeout=30000, number of retries =3, #bytes=238
>>> KDCCommunication: kdc=bbva-ad1.bf.arg.igrupobbva TCP:88, timeout=30000,Attempt =1, #bytes=238
>>>DEBUG: TCPClient reading 1500 bytes
>>> KrbKdcReq send: #bytes read=1500
>>> KdcAccessibility: remove bbva-ad1.bf.arg.igrupobbva
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
>>> KrbAsRep cons in KrbAsReq.getReply idmdesa
principal is idmdesa@BF.ARG.IGRUPOBBVA
Will use keytab
Commit Succeeded


Login:

Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt true ticketCache is null isInitiator true KeyTab is /opt/netiq/idm/apps/kerberos/idmportal.keytab refreshKrb5Config is true principal is idmdesa@BF.ARG.IGRUPOBBVA tryFirstPass is false useFirstPass is false storePass is false clearPass is false
Refreshing Kerberos configuration
Java config name: /etc/krb5.conf
Loaded from Java config
>>> KdcAccessibility: reset
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
default etypes for default_tkt_enctypes: 18 23.
>>> KrbAsReq creating message
>>> KrbKdcReq send: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000, number of retries =3, #bytes=151
>>> KDCCommunication: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000,Attempt =1, #bytes=151
>>> KrbKdcReq send: #bytes read=202
>>>Pre-Authentication Data:
PA-DATA type = 19
PA-ETYPE-INFO2 etype = 18, salt = BF.ARG.IGRUPOBBVAidmdesa, s2kparams = null
PA-ETYPE-INFO2 etype = 23, salt = null, s2kparams = null

>>>Pre-Authentication Data:
PA-DATA type = 2
PA-ENC-TIMESTAMP
>>>Pre-Authentication Data:
PA-DATA type = 16

>>>Pre-Authentication Data:
PA-DATA type = 15

>>> KdcAccessibility: remove bbva-ad1.bf.arg.igrupobbva
>>> KDCRep: init() encoding tag is 126 req type is 11
>>>KRBError:
sTime is Tue Oct 09 17:20:33 ART 2018 1539116433000
suSec is 784249
error code is 25
error Message is Additional pre-authentication required
sname is krbtgt/BF.ARG.IGRUPOBBVA@BF.ARG.IGRUPOBBVA
eData provided.
msgType is 30
>>>Pre-Authentication Data:
PA-DATA type = 19
PA-ETYPE-INFO2 etype = 18, salt = BF.ARG.IGRUPOBBVAidmdesa, s2kparams = null
PA-ETYPE-INFO2 etype = 23, salt = null, s2kparams = null

>>>Pre-Authentication Data:
PA-DATA type = 2
PA-ENC-TIMESTAMP
>>>Pre-Authentication Data:
PA-DATA type = 16

>>>Pre-Authentication Data:
PA-DATA type = 15

KrbAsReqBuilder: PREAUTH FAILED/REQ, re-send AS-REQ
default etypes for default_tkt_enctypes: 18 23.
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
default etypes for default_tkt_enctypes: 18 23.
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
>>> KrbAsReq creating message
>>> KrbKdcReq send: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000, number of retries =3, #bytes=238
>>> KDCCommunication: kdc=bbva-ad1.bf.arg.igrupobbva UDP:88, timeout=30000,Attempt =1, #bytes=238
>>> KrbKdcReq send: #bytes read=106
>>> KrbKdcReq send: kdc=bbva-ad1.bf.arg.igrupobbva TCP:88, timeout=30000, number of retries =3, #bytes=238
>>> KDCCommunication: kdc=bbva-ad1.bf.arg.igrupobbva TCP:88, timeout=30000,Attempt =1, #bytes=238
>>>DEBUG: TCPClient reading 1500 bytes
>>> KrbKdcReq send: #bytes read=1500
>>> KdcAccessibility: remove bbva-ad1.bf.arg.igrupobbva
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
>>> EType: sun.security.krb5.internal.crypto.Aes256CtsHmacSha1EType
>>> KrbAsRep cons in KrbAsReq.getReply idmdesa
principal is idmdesa@BF.ARG.IGRUPOBBVA
Will use keytab
Commit Succeeded

Found KeyTab /opt/netiq/idm/apps/kerberos/idmportal.keytab for idmdesa@BF.ARG.IGRUPOBBVA
Found KeyTab /opt/netiq/idm/apps/kerberos/idmportal.keytab for idmdesa@BF.ARG.IGRUPOBBVA
Found ticket for idmdesa@BF.ARG.IGRUPOBBVA to go to krbtgt/BF.ARG.IGRUPOBBVA@BF.ARG.IGRUPOBBVA expiring on Wed Oct 10 03:20:33 ART 2018
Entered Krb5Context.acceptSecContext with state=STATE_NEW
Looking for keys for: idmdesa@BF.ARG.IGRUPOBBVA
Added key: 17version: 0
Added key: 18version: 0
Added key: 23version: 0
Found unsupported keytype (3) for idmdesa@BF.ARG.IGRUPOBBVA
Found unsupported keytype (1) for idmdesa@BF.ARG.IGRUPOBBVA
>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
default etypes for permitted_enctypes: 18 23.
>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
MemoryCache: add 1539116434/000183/17783237A452516512894CC0F3AE7908/A100169@BF.ARG.IGRUPOBBVA to A100169@BF.ARG.IGRUPOBBVA|HTTP/idmdesa.bbva.com@BF.ARG.IGRUPOBBVA
MemoryCache: Existing AuthList:
#1: 1539116135/000180/0314FF297D2091D725C448FB2AE221BE/A100169@BF.ARG.IGRUPOBBVA

>>> KrbApReq: authenticate succeed.
>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
>>>Delegated Creds have pname=A100169@BF.ARG.IGRUPOBBVA sname=krbtgt/BF.ARG.IGRUPOBBVA@BF.ARG.IGRUPOBBVA authtime=null starttime=20181009201534Z endtime=20181010061507ZrenewTill=20181016201507Z
Krb5Context setting peerSeqNumber to: 157399255
>>> EType: sun.security.krb5.internal.crypto.ArcFourHmacEType
Krb5Context setting mySeqNumber to: 237040367
2018-10-09 17:20:34,319 [ERROR] OAuthServlet [RBPM] Login session has timed out. Log in to the application again.
com.novell.common.auth.ValidationException
at com.netiq.idm.auth.oauth.OAuthServlet.handleAuthorizationResponse(OAuthServlet.java:194)
at com.netiq.idm.auth.oauth.OAuthServlet.doGet(OAuthServlet.java:72)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.novell.common.CrossScriptingFilter.doFilter(CrossScriptingFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.novell.common.HttpSecurityHeadersFilter.doFilter(HttpSecurityHeadersFilter.java:132)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:496)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)


OSP:

Preamble: [OSP]
Priority Level: FINER
Java: internal.osp.common.logging.HttpRequestLogger.log() [181] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.903-0300
Log Data: HttpServletRequest (Number 9)
Method: GET
Request URL: /osp/a/idm/auth/oauth2/grant
Query String: response_type=code&client_id=rbpm&state=b22b4ca3-e31b-4143-a9ab-7be28030f479&redirect_uri=http%3A//idmdesa.bbva.com%3A8080/IDMProv/oauth
Scheme: http
Context Path: /osp
Servlet Path: /a
Path Info: /idm/auth/oauth2/grant
Server Name: idmdesa.bbva.com
Server Port: 8080
Locale: es_AR
Host IP Address: 10.1.23.17
Remote Client IP Address: 10.1.23.50
Headers
accept=*/*
accept-language=es-AR
user-agent=Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; WOW64; Trident/7.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C)
accept-encoding=gzip, deflate
host=idmdesa.bbva.com:8080
connection=Keep-Alive
dnt=1
Session
Id: B381FCBB49120870D5AB9750F8598CEB
Last Accessed Time: 2018-10-09T17:20:33.903-0300 (1539116433903)
Parameters
response_type
client_id
state
redirect_uri
Attributes
OSPRequestContext

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.servlet.OSPServlet.process() [213] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.903-0300
Log Data:
Class: OSPRequestContext
HttpServletResponse exists.
Http request type: GET
Request number: 9
Tenant: For IDM and IG
Service: For IDM and IG(id=auth)
Path element count: 2
Element: oauth2
Element: grant
Override locale: es_AR

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.servlets.handler.AuthenticationServiceRequestHandler.resolveHandler() [187] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.903-0300
Log Data: IDP oauth2 handler to process request received for grant

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.oauth2.handler.Grant.getCommand() [235] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.904-0300
Elapsed time: 25.492 microseconds
Log Data: Parse OAuth 2.0 response_type or grant_type:
response_type: code
Maps to: Authorization Code Grant profile

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.<init>() [315] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.904-0300
Log Data: Created new Session: id: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX, Type: PERSISTENT

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.cluster.ClusterCookieContext.resolveSession() [153] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.904-0300
Elapsed time: 384.439 microseconds
Log Data: Session was created for this user request because no cookie accompanied the request: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894
Session cached:
Class: NIDPSession
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Sub-identifier: 0
Private identifier: )u866t5WHO9Hne32*6Y%9hR]N
Type: PERSISTANT
Create time: 2018-10-09T17:20:33.904-0300 (1539116433904), elapsed: 0 (0)
Last used time: 2018-10-09T17:20:33.904-0300 (1539116433904), elapsed: 0 (0)
Main JSP: main
Set activity: true
Storage cache: <none>
Logout flag: 0
Show logout: false

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.checkAuthenticated() [2554] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.905-0300
Elapsed time: 20.49 microseconds
Log Data: Session authenticated?
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894
Zero consumed authentications.
Authenticated: false

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.session.NIDPSession.getSessionData() [734] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.905-0300
Elapsed time: 27.801 microseconds
Log Data: Get session data based on request:
Creating new session data; id: 1

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.oauth2.handler.InterRequestPackage.forward() [323] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.905-0300
Elapsed time: 352.360 microseconds
Log Data: Assigned package id: 1539116433905--846542199
Setting cookie:
Name: x-oidp-oauth2-1539116433905--846542199
Value: cnQ9WTI5a1pRfn4tIy1pPU16VTBaakppTXpVM1pqSmhZV05oWlRGa05EZ34tIy1yPWFIUjBjRG92TDJsa2JXUmxjMkV1WW1KMllTNWpiMjA2T0RBNE1DOUpSRTFRY205MkwyOWhkWFJvLSMtaD1iRlZPV1dFclZXSkxaSGxwYVVrd1VFWTNXSE5EVVZwRVNtRlRTekJFYjBGUk1HbDNjbWx1ZEc5WGF6MH4tIy10PVlqSXlZalJqWVRNdFpUTXhZaTAwTVRRekxXRTVZV0l0TjJKbE1qZ3dNekJtTkRjNQ~~
Encrypted bytes: 304
Base64-encoded characters: 408
Domain: idmdesa.bbva.com
Path: /
Maximum age (seconds): unlimited
Secure: false
HttpOnly: true

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.profile.LoginProfile.login() [187] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.906-0300
Log Data: Processing login request with TARGET: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=354f2b357f2aacae1d48&client_id=rbpm&irdpkg=1539116433905--846542199, Saved TARGET: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=354f2b357f2aacae1d48&client_id=rbpm&irdpkg=1539116433905--846542199, Force: false.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.setExecutables() [270] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.906-0300
Log Data: Number of contract executables set to run: 3

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.setExecutables() [275] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.906-0300
Log Data: Introductions are set to execute.

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.LoginProfile.getContractToExecute() [429] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.906-0300
Elapsed time: 499.452 microseconds
Log Data: Get contract to execute:
Existing contract execution profile: false
Get authentication contract by card identifier:
Card identifier: none
Contract: none found
Get default contract:
Select IDP contract when no configuration-specified default: true
Default contract group: none
Default contract: User Kerberos Login(id=krb-contract)
No specified contract. Default: User Kerberos Login(id=krb-contract)
New contract execution profile created:
Contract: User Kerberos Login(id=krb-contract)
Card identifier: krb-contract-$default-card$

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.setMessage() [990] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.907-0300
Log Data: Setting session message to null

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.exec() [484] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.907-0300
Log Data: Executing contract User Kerberos Login.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [723] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.907-0300
Log Data: Contract executable executing: Introductions

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [882] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.907-0300
Elapsed time: 26.236 microseconds
Log Data: Contract executable completed:
Method: Introductions
Class: internal.osp.oidp.service.protocol.authentication.classes.IntroductionClass
Status: NotAuthenticated
Move to next executable: false

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.getNextExecutable() [678] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.908-0300
Elapsed time: 25.824 microseconds
Log Data: Get next contract executable:
Executables count: 3
Counter: 0
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Type: user-authenticate
Session authenticated: false
Valid on session: false
Method selected for execution.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [723] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.908-0300
Log Data: Contract executable executing: (Auto) Kerberos Authentication Method

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.doAuthenticate() [198] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.908-0300
Log Data: Received Request from Remote address 10.1.23.50

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.doAuthenticate() [215] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.908-0300
Log Data: Returning NEGOTIATE header

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.buildContractRedirect() [347] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.908-0300
Log Data: Contract redirect URL: /osp/a/idm/auth/oauth2/grant?response_type=code&client_id=rbpm&state=b22b4ca3-e31b-4143-a9ab-7be28030f479&redirect_uri=http%3A//idmdesa.bbva.com%3A8080/IDMProv/oauth&acAuthCardId=np-contract-%24default-card%24&preferQueryStringContract=true&sid=1

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [882] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.909-0300
Elapsed time: 12.410 microseconds
Log Data: Contract executable completed:
Method: (Auto) Kerberos Authentication Method
Class: internal.osp.oidp.spnego.authclass.SpnegoClass
Status: ShowPage
Required additional interaction: true
Move to next executable: false

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.exec() [493] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.909-0300
Log Data: Executing methods returned status: SHOW_PAGE

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.exec() [551] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.909-0300
Log Data: UIResponder set to JSP response.

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.LoginProfile.executeContract() [703] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.909-0300
Elapsed time: 3.683 microseconds
Log Data: Contract execution profile "execute" returned status: HandledRequest

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.servlets.handler.AuthenticationServiceRequestHandler.commit() [535] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.909-0300
Elapsed time: 18.542 milliseconds
Log Data: Persisting session: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Session to cookie: true

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.UIResponder$PageResponse.setSpecificResponse() [2093] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.928-0300
Log Data: Forwarding:
Class: PageToShow
Page: /idm/jsp/no_kerberos.jsp
Attribute count: 4
FilterAuthenticationClass.dup-res-data=LblYPSTAOqNNXcs/X31ceTXhd9oBEkbIypaDfChelznJGeMZwEoIof/74dfZwlDy
FilterAuthenticationClass.dup-res-state=OFF
kerberos.delay-seconds=5
kerberos.redirect-url=/osp/a/idm/auth/oauth2/grant?response_type=code&client_id=rbpm&state=b22b4ca3-e31b-4143-a9ab-7be28030f479&redirect_uri=http%3A//idmdesa.bbva.com%3A8080/IDMProv/oauth&acAuthCardId=np-contract-%24default-card%24&preferQueryStringContract=true&sid=1

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.UIResponder$Response.setResponse() [1388] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.939-0300
Log Data: Response: PAGE
Class: PageToShow
Page: /idm/jsp/no_kerberos.jsp
Attribute count: 4
FilterAuthenticationClass.dup-res-data=LblYPSTAOqNNXcs/X31ceTXhd9oBEkbIypaDfChelznJGeMZwEoIof/74dfZwlDy
FilterAuthenticationClass.dup-res-state=OFF
kerberos.delay-seconds=5
kerberos.redirect-url=/osp/a/idm/auth/oauth2/grant?response_type=code&client_id=rbpm&state=b22b4ca3-e31b-4143-a9ab-7be28030f479&redirect_uri=http%3A//idmdesa.bbva.com%3A8080/IDMProv/oauth&acAuthCardId=np-contract-%24default-card%24&preferQueryStringContract=true&sid=1

Preamble: [OSP]
Priority Level: FINER
Java: internal.osp.common.logging.HttpResponseLogger.log() [138] thread=http-nio-8080-exec-6
Time: 2018-10-09T17:20:33.940-0300
Log Data: HttpServletResponse (Number 9)
Duration (seconds): 0.39
Content type: text/html;charset=UTF-8
Character encoding: UTF-8
Locale: en
Buffer size: 8192

Preamble: [OSP]
Priority Level: FINER
Java: internal.osp.common.logging.HttpRequestLogger.log() [181] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.943-0300
Log Data: HttpServletRequest (Number 10)
Method: GET
Request URL: /osp/a/idm/auth/oauth2/grant
Query String: response_type=code&client_id=rbpm&state=b22b4ca3-e31b-4143-a9ab-7be28030f479&redirect_uri=http%3A//idmdesa.bbva.com%3A8080/IDMProv/oauth
Scheme: http
Context Path: /osp
Servlet Path: /a
Path Info: /idm/auth/oauth2/grant
Server Name: idmdesa.bbva.com
Server Port: 8080
Locale: es_AR
Host IP Address: 10.1.23.17
Remote Client IP Address: 10.1.23.50
Cookies
(1 of 3): JSESSIONID=B381FCBB49120870D5AB9750F8598CEB
(2 of 3): x-oidp-oauth2-1539116433905--846542199=9TC8P@z5t8Gq6etz3E@TtXq2Ajaseg523bCPRrPlRfkjcykpWttj6kYJl7kuHH0FBVgGHmvT8XDf0lMAZj1SXfM673HiqjCFwOjHr0CE09IyLaWcrQXUkf07G6Z03TSYJXVA/cW/6wOGoo27u/zKcYQO1BNbe9E/NRDIVFefleclEMekA/dNfZukok4a50XAnYAgvc/1f6Z1xD99gr2b9X6JTDYqEUoMDCKGfX6vaZPO10wfZ13H1tCjXrbpoxrvHdw12@PtEbb9AghGNlB8UWFK9sYXegsjFRPFopYSWpLab5FcLmlW6Bj@ficVjwFfvjLbmji@Z9AYowZZOgIus1iD8/OcSu1IzKtADVqRZRDHdLrne1dj4PG0I/wldXwRwT23HvW/LmBxaSmUMcptPg~~
(3 of 3): x-oidp-session59303d34382c2d310=200-345NNJLGRYDXFVM4PW3H64EPEOPBT4FGHHHASJ/P-580F1769-8487!1!8488!120!127!kmYwGqCeEgRR94W7uRe5qcrTn5nj24PYdMptdPgMEvs~!/hjfJTd8NPDLyAzOrOjIeZ2GWtdcZm/0ePmLcs3vPN5R4LQQdizu5gLo/evP8kR13FqTtGb6uyKAANKaJkDTqQIczvlB66lkTRkGVdPi3hcnRCZgz14pYTRKVXVpqNEqwDLZTubzVLPT0FKvQWqqoc0cIRdxop1CsWGi6fUehpcKG78UCIEJye0lmWTZ6pYnb96VAjBcMSTjcESM1yeNQhQFuvz9pFcwTk6ENMBJwWBSEzxgkXsZHe0x10ueyJUOizpjTZCgHJ4nDEFMEMgrNbZSTg5DCcBEipfXB9oaeOxVqlX04GFPCcIPb3Bl1p3jF87z1aa6H/Sha0qmbka7AmhbY1v60f8+xnVye1WzDPOdeyLh0By0wbQQJMm/Lo5H/2ZuCpVR7EZUZo1f1nKDVl3EDM8UwABt45FQnbyD3UsX4Jmr8u24PT9wgwCwvnh7UDtvKXTRat4Bi/jvk7I2zoYnUX5IQU/BlNyYnJTjyqvdbDlKickCCa3y1s1/yAhlFkeSCWhyVWXs6bj613Fd4RNGeb3zwwoYM3xnvV9V4V1g1cIU/7trVrWdAZflLdDtb+1lBNYKBswgluqqBlF00DI8VNJ4cC75pmhkgtAb6VnGwbQuAgqlPYFBgCpHDrC6ImFQqzaGp9Xvtc/LLk5XhQ~~
Headers
accept=*/*
accept-language=es-AR
user-agent=Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; WOW64; Trident/7.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C)
accept-encoding=gzip, deflate
host=idmdesa.bbva.com:8080
cookie=(see above)
connection=Keep-Alive
dnt=1
authorization=Negotiate YIINXwYGKwYBBQUCoIINUzCCDU+gMDAuBgkqhkiC9xIBAgIGCSqGSIb3EgECAgYKKwYBBAGCNwICHgYKKwYBBAGCNwICCqKCDRkEgg0VYIINEQYJKoZIhvcSAQICAQBugg0AMIIM/KADAgEFoQMCAQ6iBwMFACAAAACjggU0YYIFMDCCBSygAwIBBaETGxFCRi5BUkcuSUdSVVBPQkJWQaIjMCGgAwIBAqEaMBgbBEhUVFAbEGlkbWRlc2EuYmJ2YS5jb22jggTpMIIE5aADAgEXoQMCAQSiggTXBIIE07og+HB6WfEWIaVm+6TLkcZdbcOomU/0J6VsUQx79S+ZnS+36s2m6ZsRuyh/JbgnSqY3f/iDfvy2oK7UuCPaVSVo1SUkQonT0RmeBu9h396MZdasrK+TB+Wtfb/70cBFjc4KoicyWu5yGhNiSjKPNHH8GSh8eEkxYzh57jy+6fZQ7BfQSA8NVbQWX3oh21Xb3Y/Yml4JdIuukbYVNqQllxk2ZRXDRC4bzZsy3k7Tjw8eyo4+m5R7bab8LFaTqIZxQ1f+1ndn9wB5PImedP6hlwMypS/HWQqP0K4vwR+0RkyQhenEPESj1DvYkY7uUsKOgtK+nBy2am6FOEq3BuMdMUeKekKlDXMLPz1PjjBkKYCrSO51X6hcPlpBbnMxuz8mN0CjI1J5L39NQBZAjAgUCURLG21PMctYuJN0XO/8jSyRmsbf48qyRc3t8PezdlJlHPmoBzXcWStoP53UL0iAHY2nfABPWjo8WAzXX5I2zaZr9a3eHqknBytbMI7l6sgIPyp5QiPs00nb79fgamzVtwKbH09YkHprAOBKnVFfssJyxNqo+iTSu+3m/zzgm3XB4xL+Wcm32yK/jwEa8gM19WoQwB5GBX5vPkYNduWOrRmGWyeoWg0dllfW2M7ulKZRuLqvY52CFN2tFXME05uFejdz+JIbSQ3SrvBP4wi8LqUXMGlzoYVgQDrckYbxzkuVYJjsX5SfdjfVCu+hgam+kRjW4PjA9ewY96/o1uTtWFLXxiWAZclEBqInp8uC7YhE1/sM02eKP1cBYiBOrAOGgKjnrrFGAAl3RWaDbJZ2791xINzKrzJV5hsbz9v+4bgv2281h0iWmMUkzVssFImBTnLRHDCCKsUjgRBUuuAzclPTWXpU7wZRjEAflbsHsvaNmpibEgyrc34eWIAqc4E2nQLkW98XHAuDqKsj/Nq2zDoRjNw7tGumwwRO8pQihMKTFhkfeNcqQcFje4E1b6KaBX7QkQspBuHvzpoehGCIHCeBXR17e+dx8VCICHqWgYjr4OaruXr+9ZSRAXvBhOnMUpIErVQRhVJH82RVoJUSjkf2qCN+7iwpg9O/xQZ/syI+ExW2/EIQLbs4MtCRUYRyHd7xdXgHVSz+O3aqShERwak7UYxBMawueeyDF+h5AMOhyVgDZpAjYetmI8GhAw4jTpFwAW58/CxOOuq49q3H+ouypptq5+iEiP4G8fevkXZWZtlMyYcceE5If/nUrYuPS3zer5eil5ZpZwkFc722aM+AXnK9Bvclmpi8qFX97YOwV1v98qxKYHTxVgKYcpWFDUbt3aWskr5zJMOUHhWqdiEDvIbTpgl/tw2nY9ELx2NMvDMPXRQac0m2uUzdQkavQ7ojkez7p2JhZDp49flW/YgmOggkOZPwUaf+04YKgnULlNiFK1NDImduJLzr7YjutTyziNuLl2/tKPgUL0eQz+40AwUCq2rIeTzf1kCBTPmI3OFK8L5tVpoJRMZSZNXh8JMk/DBKfJv46oZxlm9NPZzcCO1zCV1xeWwmNMVOepKvfRsZotZZ+2vywN92MQDZlY/tUZIZqIPA1B+G3kjMgwNjvQOpAYFZ0GIYceze/UtE1aap+l8jDdh19EPZouw2iDecaetxk7oTB5Gvcoxs/01SgyOapIIHrTCCB6mgAwIBF6KCB6AEggecx2NEcGdRjL7nAMKVKYR2VmrguQJsoHqz3vTXN1M/lIavBg0sbjwvPCHtfRh+Kwb7uAJFyFoAme1rWqO5qf6ls818xzWrgS7gNjfq0PkeHmHnhMU6rUPLDoMflZmiSgQcSyxHSzxgtdGhfknK9Ic3sTMcAxKFPdp64l4kxTcK5KPmbKPaPVn2/NwsS2HHoWo8WFkZbzcddUaLnD1nxI2xdDeSblzh+aBc5OT7edg5W3BNJ6DwcRYKBi8i6X5lGz1Bj6x84dYxmONqGrNGKJUsEDOUigUVcLEAQ3JGWs53bIUvQuMHuui4u5lo7HRhlWlFgOfuvLhMN7d6DJTDro77RBXlIo/Mn8TP4H7M2+DdAQmFBlgqJgSBpYHGo5LxrrbYsMQ5CkcWRg/h/2D6f6Q2O5GwTO0ilZ/GSgG7WJfBKKDQZo/hNTsu1US6C8mjVnW/6kO58+0PkyjlReXwtizWBwIOQcnDDTogJHPmfTLXgb3p4cpKwS7dAEYt7jxsj8Wgk9smJOqfgeHyX/5wuelFRKAMEKdamvjx+OmGtl07RC7bI3wTV8HU19d/G1yRBehSRWw6V9SDCs5GffVc2YbxI9c751iciIJOMVNmT+rhdcCvCZnV2Pvg7Gtt0EDtqb6feWd2WJiR5hh3KeeH/9g8GL0WiJDfKGFi3/nOdVKXaqNTw2VmeIlNrsWv66VtUekTuCaCMRp3QgzE3eTLl8dvqwFRUuJUjX+5ZzsWvqwrMJs+8PQR8DVW1HtxUcjrj+idUyRg9c/dLpla1GvzhIPFGVSFnmvGMDliHhE9RPyZhXErrEnyx+4XYblCqfxsa7kVbgUJ65oq4EvhtwYgOkzWAbOC4uXfpCplSdTcLmYt94Mac94XbMLw2KAwW7SMCS5EAmTygPyyo3nFScjmawUcsXrIpBk/cnHdXhHe7rGnoQfDaWOUsI4QedTc0RfgqcrpgOUkUm+Bwcweg3V9U2kjrom59mMtNVHlPuPlmdenP4a79tZQbnwWs4LJWB1XMGTTAii3I4DygK3t+lUneLF6vdrlYrM5LQursyq2RgOqxDKm0qrcolOZkMI8cEMPd/a5gy+X9gqsnitsBwuuoS+1L2A/pHBsIwAnufAjl8puus6KFowXcC53yfdlotZ3sOVazOIVb3gFQBP9LfTfp1DDTTFyRfCcLGh3B2WouFuxC7gyewnT3araIAqFRojroltWgpOicqHhx2V0guXKg6z9ruRwwk6KeGPcu6ZccsGKH/9CTfsKKZaDVbQku5QNVB9VcRgz5ekMyDrmaQ5KHwfWDJKlw6TOk10/h/n1KXuU/PoMAjeehxfEQybPQrCr22W66+kWZHY8ilUqR0UQgUIDEnyZYctNhAZNpV58QHIl3XueOgwYAUioMrhT7Y40fHzRBajgGZsOKf8TuZ97JXouTvUSylYxXFljpawIpVzkJmxIfUNrPFNQhvRdoKcY0enhtfor5NrcITZs1tThZt9QoI27Cd9jutpBVgkSr01DxuNbabKt0QPqLfzxvrS3XgbOZAkndWJwP9F6ejDFeSwcL9V1gOXQ+ZtD/SyUdHNhKkrEl46gZzlIebuTwiFmpSXQJINo3iI5hHIoRt/PHeMllAPY4tl3X/qZmWF8FOgSvFeaoB2DwCtZstHMr/iCYsErAaKM5o62bbgS6LYMm9ImclvlFXAj8DhtCD6+DDHb3Lne2Ta2cMz2x4vPwbdIaDuavgUL+JEbWsouYKJWaAUePm/AgxsGp0Rit7KJsPx8fuekLCmE25qisAadiLWbqqFPROUP4JcKGzcedv3868/haWOhp0hPbPpLRZNMsOLTNVP344Q0LCd7DnF3ZkmbUaERgSURpz1pAQ9HJyYDHUHPHUNX7Pk+Lv9eXMqgE3HuXGtMo7SJ8RIqaEHKV1ZF17a6uW8sZHb0SkaXmCvxOL5HxFft1abrk+xv1jgu8wDKnuGAImjovg8E3PktJ4bPp4qyPzlPcvUjxFuHee0f+NO2AyLK7fJ9yFO57lBaNCSvsoVVSXbFXWjRYcgGCuEzbNdYwyMN+89TBxA0mgMWL0fN3WfSFcw93EQFakL5yH2dLueNR4Tw5F7ZVk8Us+24FllVW9/ry5lCyNrFN1GDHMJ29WYzggZELL9ZUDmrSVEi+8ZiY2DbSxIgBz/tlDcF/aFJ8GKPBBRuoG5QLpIgWHKGkJv+7OcMYhJdWAwhRQtafFOU+upo/wboQmsMWTjd6hP+4Ii7xQupbQR7oJZlDS+eAS/jWhsE/geRH2qw2EliMK6yEvDrTbxumb9vXoVxgaJl9n3C+WQUJGKSnzvUON7XQGzlDMEnAI/mtvpkqY0YXLWT+fodrmuMr4lBHgYLMHQjzP/BZ5DMv7w+oFJL+yq3YcyFSwFsLGQX0HU9Av7ag6Aw+Onn5Ct54eUNL5O5+gS13tHDyDpJl/zx23sPDWX4BoPECcwMOJIciJvPhopMVrb79bChiLrrSHPYR5/VsUYPofpmxWi+Gm5zrZgRyOLkPBmauOIP6VK21AYWaEVluy0thnFXarC8OPGt+w0QJjCyHA/sQCe9dbGQ5AOq0NCTuCOS0UhynkbfeVLtgw==
Session
Id: B381FCBB49120870D5AB9750F8598CEB
Last Accessed Time: 2018-10-09T17:20:33.940-0300 (1539116433940)
Parameters
response_type
client_id
state
redirect_uri
Attributes
OSPRequestContext

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.servlet.OSPServlet.process() [213] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.944-0300
Log Data:
Class: OSPRequestContext
HttpServletResponse exists.
Http request type: GET
Request number: 10
Tenant: For IDM and IG
Service: For IDM and IG(id=auth)
Path element count: 2
Element: oauth2
Element: grant
Override locale: es_AR

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.servlets.handler.AuthenticationServiceRequestHandler.resolveHandler() [187] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.944-0300
Log Data: IDP oauth2 handler to process request received for grant

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.oauth2.handler.Grant.getCommand() [235] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.944-0300
Elapsed time: 22.720 microseconds
Log Data: Parse OAuth 2.0 response_type or grant_type:
response_type: code
Maps to: Authorization Code Grant profile

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.setExecutables() [270] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.946-0300
Log Data: Number of contract executables set to run: 3

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.<init>() [456] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.946-0300
Log Data: Built Session from XML: id: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX, Type: PERSISTENT

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.reapSessionData() [795] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.946-0300
Elapsed time: 7.401 microseconds
Log Data: Clean up expired session data instances:
No expired instances found.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.isAuthenticated() [2585] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.946-0300
Elapsed time: 15.90 microseconds
Log Data: Session authenticated?
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894
Zero consumed authentications.
Authenticated: false

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.cluster.ClusterCookieContext.resolveSession() [153] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.946-0300
Elapsed time: 166.215 microseconds
Log Data:
Session cached:
Class: NIDPSession
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Sub-identifier: 0
Private identifier: )u866t5WHO9Hne32*6Y%9hR]N
Type: PERSISTANT
Create time: 2018-10-09T17:20:33.904-0300 (1539116433904), elapsed: 0.042s (42)
Last used time: 2018-10-09T17:20:33.909-0300 (1539116433909), elapsed: 0.037s (37)
Main JSP: main
Set activity: true
Storage cache: <none>
Session data key: 1
Class: NIDPSessionData
Id: 1
Create time: 2018-10-09T17:20:33.905-0300 (1539116433905), elapsed: 0.042s (42)
Target stack:
0: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=354f2b357f2aacae1d48&client_id=rbpm&irdpkg=1539116433905--846542199
Class: ContractExecutionProfile
Service: For IDM and IG(id=auth)
Request: /osp/a/idm/auth/oauth2/grant
Reset: false
First Time: true
Passive: false
Force: false
Counter: 0
Return URL: http://idmdesa.bbva.com:8080/osp/a/idm/auth/app/login?acAuthCardId=krb-contract-%24default-card%24&sid=1
Top: false
Authenticated: false
Credential Update: false
Class: AuthenticationContract
Id: krb-contract
Name: User Kerberos Login
URI: idm:login:user:kerberos
Trust Level: 0
Timeout: 0
Check Trust Level: false
Show Pwd Expired UI: true
Remote: false
Default: true
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Executable: (Auto) Kerberos Principal Mapping Method(id={$auto}-krb-mapping-method)
Executable: (Auto) IDM Admin Role Mapping Method(id={$auto}-admin-role-mapping-method)
Authentication Card: User Kerberos Login-$default-card$(id=krb-contract-$default-card$)
Logout flag: 0
Show logout: false
Markup:
Class: NameValuePair
Name: no-nego
Value: true
Persistent: true

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.session.NIDPSession.getSessionData() [734] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.947-0300
Elapsed time: 15.942 microseconds
Log Data: Get session data based on request:
Creating new session data; id: 2

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.oauth2.handler.InterRequestPackage.forward() [323] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.947-0300
Elapsed time: 321.815 microseconds
Log Data: Assigned package id: 1539116433947--1291448215
Searching for cookie(s):
Prefix: x-oidp-oauth2-
Total cookies: 3
Found count: 1
Setting cookie:
Name: x-oidp-oauth2-1539116433947--1291448215
Value: cnQ9WTI5a1pRfn4tIy1pPU9HWTFZVFV3TlRSbE1UTmpaak16WTJabU16SX4tIy1yPWFIUjBjRG92TDJsa2JXUmxjMkV1WW1KMllTNWpiMjA2T0RBNE1DOUpSRTFRY205MkwyOWhkWFJvLSMtaD1iRlZPV1dFclZXSkxaSGxwYVVrd1VFWTNXSE5EVVZwRVNtRlRTekJFYjBGUk1HbDNjbWx1ZEc5WGF6MH4tIy10PVlqSXlZalJqWVRNdFpUTXhZaTAwTVRRekxXRTVZV0l0TjJKbE1qZ3dNekJtTkRjNQ~~
Encrypted bytes: 304
Base64-encoded characters: 408
Domain: idmdesa.bbva.com
Path: /
Maximum age (seconds): unlimited
Secure: false
HttpOnly: true

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.profile.LoginProfile.login() [187] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.948-0300
Log Data: Processing login request with TARGET: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=8f5a5054e13cf33cff32&client_id=rbpm&irdpkg=1539116433947--1291448215, Saved TARGET: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=8f5a5054e13cf33cff32&client_id=rbpm&irdpkg=1539116433947--1291448215, Force: false.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.setExecutables() [270] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.948-0300
Log Data: Number of contract executables set to run: 3

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.setExecutables() [275] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.948-0300
Log Data: Introductions are set to execute.

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.LoginProfile.getContractToExecute() [429] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.948-0300
Elapsed time: 432.710 microseconds
Log Data: Get contract to execute:
Existing contract execution profile: false
Get authentication contract by card identifier:
Card identifier: none
Contract: none found
Get default contract:
Select IDP contract when no configuration-specified default: true
Default contract group: none
Default contract: User Kerberos Login(id=krb-contract)
No specified contract. Default: User Kerberos Login(id=krb-contract)
New contract execution profile created:
Contract: User Kerberos Login(id=krb-contract)
Card identifier: krb-contract-$default-card$

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.setMessage() [990] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.949-0300
Log Data: Setting session message to null

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.exec() [484] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.949-0300
Log Data: Executing contract User Kerberos Login.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [723] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.949-0300
Log Data: Contract executable executing: Introductions

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [882] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.949-0300
Elapsed time: 17.224 microseconds
Log Data: Contract executable completed:
Method: Introductions
Class: internal.osp.oidp.service.protocol.authentication.classes.IntroductionClass
Status: NotAuthenticated
Move to next executable: false

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.getNextExecutable() [678] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.949-0300
Elapsed time: 26.821 microseconds
Log Data: Get next contract executable:
Executables count: 3
Counter: 0
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Type: user-authenticate
Session authenticated: false
Valid on session: false
Method selected for execution.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [723] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.950-0300
Log Data: Contract executable executing: (Auto) Kerberos Authentication Method

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.doAuthenticate() [198] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.950-0300
Log Data: Received Request from Remote address 10.1.23.50

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.doAuthenticate() [227] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.950-0300
Log Data: Parsed credentials: type: Negotiate, value: exists

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.doAuthenticate() [243] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.950-0300
Log Data: Attempting Kerberos authentication.

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.spnego.authclass.KerberosDataSource$KerberosAuthentication.process() [336] thread=localhost-startStop-1
Time: 2018-10-09T16:14:54.164-0300
Log Data: Kerberos GSS:
Context established: true
Client: A100169@BF.ARG.IGRUPOBBVA
Server: idmdesa@BF.ARG.IGRUPOBBVA
Lifetime (minutes): 35791394
Mutual Authn State: true
Mutual Authn: A100169@BF.ARG.IGRUPOBBVA
Seq Detect state: false
Replay Detect state: false

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.spnego.authclass.KerberosDataSource.authenticate() [242] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.994-0300
Log Data: Kerberos Principal match found in the userstore.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.attributes.cache.CacheAttributeSource.addAttributes() [150] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.994-0300
Elapsed time: 23.139 microseconds
Log Data: Adding cached attributes:
krbPrincipalName
{$principalRealm}
{$principal}

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.spnego.authclass.SpnegoClass.doAuthenticate() [269] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.994-0300
Log Data: Set principal: null

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [882] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.994-0300
Elapsed time: 22.603 microseconds
Log Data: Contract executable completed:
Method: (Auto) Kerberos Authentication Method
Class: internal.osp.oidp.spnego.authclass.SpnegoClass
Status: Authenticated
Move to next executable: true

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.getNextExecutable() [678] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.995-0300
Elapsed time: 23.477 microseconds
Log Data: Get next contract executable:
Executables count: 3
Counter: 1
Executable: (Auto) Kerberos Principal Mapping Method(id={$auto}-krb-mapping-method)
Type: user-map
Session authenticated: false
Valid on session: false
Method selected for execution.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [723] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.995-0300
Log Data: Contract executable executing: (Auto) Kerberos Principal Mapping Method

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.attributes.cache.CacheAttributeSource.getAttributes() [318] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.995-0300
Elapsed time: 11.699 microseconds
Log Data: Requested Attributes: krbPrincipalName
Cached Attribute Value: #1: empty: false, multi-valued: false

Priority Level: FINEST
Java: internal.atlaslite.jcce.ldap.jndi.JNDIConnectionPool.retireOldConnections() [1138] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.995-0300
Log Data: Closing LDAP connection due to connection timeout! Interval: 299320, Timeout: 10000, Connection: Id: a5ac7c8d-df30-41cc-98dc-be1f34671ead, host: 10.1.23.10

Priority Level: INFO
Java: internal.atlaslite.jcce.ldap.jndi.JNDIConnectionPool.retireOldConnections() [1152] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.996-0300
Log Data: Retire Conn:a5ac7c8d-df30-41cc-98dc-be1f34671ead, Invalidated

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.source.ldap.LDAPSource.search() [703] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:33.995-0300
Elapsed time: 195.49 milliseconds
Log Data: Search for LDAP principal:
Store: LDAP Directory Data Source(id=idm_idv)
Admin search:
Context: ou=Accounts,o=Meta
Scope: subtree
Filter: (cn=A100169)
Attributes: cn, fullName, givenName, GUID, initials, loginIntruderAttempts, mail, mobile, nrfMemberOf, objectClass, sn, srvprvPreferredLocale
Get next available admin connection:
Get admin connection from pool:
Pool: PLde91d526-83ce-487e-b210-069c0289b364:af7b7657-fa2e-4dc3-ab00-fae44006d6a6
Reserve connection:
Type: ADMIN_CONNECTION
Retired admin connection count: 1
New reservation (non-existing): 0dcbf39f-d44a-4f05-9018-6128c354df25
New LDAP connection:
Connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
User store: LDAP Directory Data Source(id=idm_idv)
Replica: LDAP Directory Data Source/10.1.23.10:636(id=af7b7657-fa2e-4dc3-ab00-fae44006d6a6)
Username: cn=admin,ou=Services,ou=Accounts,o=Meta
Type: ADMIN_CONNECTION
Parameters:
java.naming.factory.initial: com.sun.jndi.ldap.LdapCtxFactory
java.naming.provider.url: ldaps://10.1.23.10:636
com.sun.jndi.ldap.connect.timeout: 15000
java.naming.security.principal: cn=admin,ou=Services,ou=Accounts,o=Meta
java.naming.security.authentication: simple
java.naming.security.credentials: ********
java.naming.security.protocol: ssl
java.naming.ldap.factory.socket: internal.osp.framework.util.net.client.OSP_SSLSocketFactory
Added property to LDAP connection environment:
java.naming.ldap.attributes.binary: GUID nDSPKITrustedRootCertificate
Created new connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
Try connection: 10.1.23.10
Result count: 1
Put connection:
Connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
No pending reservation, check in connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
Admin search:
Context: ou=Services,ou=Accounts,o=Meta
Scope: subtree
Filter: (cn=A100169)
Attributes: cn, fullName, givenName, GUID, initials, loginIntruderAttempts, mail, mobile, nrfMemberOf, objectClass, sn, srvprvPreferredLocale
Get next available admin connection:
Get admin connection from pool:
Pool: PLde91d526-83ce-487e-b210-069c0289b364:af7b7657-fa2e-4dc3-ab00-fae44006d6a6
Reserve connection:
Type: ADMIN_CONNECTION
Wait filled from existing admin connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
Obtained existing connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
Try connection: 10.1.23.10
Result count: 0
Put connection:
Connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
No pending reservation, check in connection: 6eac6358-72fe-40d4-9f83-6c4858f74d7b
Found objects:
cn=A100169,ou=People

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.attributes.cache.CacheAttributeSource.addAttributes() [150] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.191-0300
Elapsed time: 43.75 microseconds
Log Data: Adding cached attributes:
userCN
fullName
first_name
mail
saml2-mapping-attr
roles
{$authsource.ObjectNameAttr}
last_name
dn
userDN

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.authentication.classes.PrincipalMapping.doAuthenticate() [627] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.191-0300
Log Data: principal mapping succeeded, returning authenticated

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [882] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.192-0300
Elapsed time: 26.67 microseconds
Log Data: Contract executable completed:
Method: (Auto) Kerberos Principal Mapping Method
Class: internal.osp.oidp.service.authentication.classes.PrincipalMapping
Status: Authenticated
Move to next executable: true

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.getNextExecutable() [678] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.192-0300
Elapsed time: 40.500 microseconds
Log Data: Get next contract executable:
Executables count: 3
Counter: 2
Executable: (Auto) IDM Admin Role Mapping Method(id={$auto}-admin-role-mapping-method)
Type: non-user
Session authenticated: false
Valid on session: false
Method selected for execution.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [723] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.192-0300
Log Data: Contract executable executing: (Auto) IDM Admin Role Mapping Method

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.authentication.classes.RoleMapping.doAuthenticate() [200] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.192-0300
Elapsed time: 124.536 microseconds
Log Data: Principal 'cn=A100169,ou=People,ou=Accounts,o=Meta' not selected for role assignment.

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.authenticateMethod() [882] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.193-0300
Elapsed time: 14.955 microseconds
Log Data: Contract executable completed:
Method: (Auto) IDM Admin Role Mapping Method
Class: internal.osp.oidp.service.authentication.classes.RoleMapping
Status: Authenticated
Move to next executable: true

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.getNextExecutable() [678] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.193-0300
Elapsed time: 5.609 microseconds
Log Data: Get next contract executable:
Executables count: 3
Considered all contract executables and none need be executed.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.exec() [493] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.193-0300
Log Data: Executing methods returned status: AUTHENTICATED

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.exec() [641] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.194-0300
Log Data: Authenticated Principal: A100169

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.UserIDProfile.validateIdentifiedPrincipal() [136] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.194-0300
Log Data: Session not authenticated. Principal considered valid.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.authentication.NIDPAuthentication.<init>() [77] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.194-0300
Log Data: Created new Local consumed authentication.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.authenticateSessionByContract() [789] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.194-0300
Log Data: Created new authentication context:
Type: NIDPAuthnContext
Profile: ContractExecutionProfile
Authentication instant: 2018-10-09T17:20:34.194-0300 (1539116434194)

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.authentication.NIDPAuthentication.addAuthnContext() [361] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.195-0300
Log Data: Class: NIDPLocalAuthentication
Identity Id: 9d26afd47be49549bb839d26afd47be4
Display Text: krb-contract-$default-card$
Consumed: true
AuthnContext Objects:
Class: NIDPAuthnContext
Auth instant: 2018-10-09T17:20:34.194-0300 (1539116434194), elapsed: 0.001s (1)
Last used time: 2018-10-09T17:20:34.194-0300 (1539116434194), elapsed: 0.001s (1)
Authentication types: Kerberos
Mag Context: false
Class: AuthenticationContract
Id: krb-contract
Name: User Kerberos Login
URI: idm:login:user:kerberos
Trust Level: 0
Timeout: 0
Check Trust Level: false
Show Pwd Expired UI: true
Remote: false
Default: true
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Executable: (Auto) Kerberos Principal Mapping Method(id={$auto}-krb-mapping-method)
Executable: (Auto) IDM Admin Role Mapping Method(id={$auto}-admin-role-mapping-method)
Authentication Card: User Kerberos Login-$default-card$(id=krb-contract-$default-card$)

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.session.NIDPSession.setAuthPrincipal() [1426] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.195-0300
Elapsed time: 39.86 microseconds
Log Data: Setting the authenticated principal:
Candidate principal:
Type: LDAPPrincipal
GUID: 9d26afd47be49549bb839d26afd47be4
User identifier: cn=A100169,ou=People,ou=Accounts,o=Meta
Authentication source: bisadus
Cached attribute count: 10
No existing principal found; Candidate principal set in session: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.session.NIDPSession.authenticate() [2920] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.195-0300
Elapsed time: 40.68 milliseconds
Log Data: Authenticating session:
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Type: PERSISTANT
Add new local authentication: true

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.session.NIDPSession.authenticate() [1289] thread=localhost-startStop-1
Time: 2018-10-09T16:14:54.164-0300
Log Data: Authenticated user cn=A100169,ou=People,ou=Accounts,o=Meta in User Store LDAP Directory User Authentication with roles <Roles(null)>:

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.ContractExecutionProfile.returnFromAuthnRequest() [734] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.236-0300
Log Data: No pending request OR going to Password Expired Servlet. Status: AUTHENTICATED

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.profile.LoginProfile.executeContract() [703] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.236-0300
Elapsed time: 81.238 microseconds
Log Data: Contract execution profile "execute" returned status: Authenticated
Set authentication context:
Type: NIDPAuthnContext
Profile: ContractExecutionProfile
Authentication instant: 2018-10-09T17:20:34.194-0300 (1539116434194)

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.profile.LoginProfile.successfulAuthentication() [156] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.237-0300
Log Data: nLogin succeeded, redirecting to http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=8f5a5054e13cf33cff32&client_id=rbpm&irdpkg=1539116433947--1291448215.

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.servlets.handler.AuthenticationServiceRequestHandler.commit() [535] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.237-0300
Elapsed time: 3.302 milliseconds
Log Data: Persisting session: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Session to cookie: true

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.UIResponder$Response.setResponse() [1388] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.241-0300
Log Data: Response: TARGET
Target: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=8f5a5054e13cf33cff32&client_id=rbpm&irdpkg=1539116433947--1291448215

Preamble: [OSP]
Priority Level: FINER
Java: internal.osp.common.logging.HttpResponseLogger.log() [138] thread=http-nio-8080-exec-5
Time: 2018-10-09T17:20:34.241-0300
Log Data: HttpServletResponse (Number 10)
Duration (seconds): 0.298
Character encoding: ISO-8859-1
Locale: en
Buffer size: 8192

Preamble: [OSP]
Priority Level: FINER
Java: internal.osp.common.logging.HttpRequestLogger.log() [181] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.262-0300
Log Data: HttpServletRequest (Number 11)
Method: GET
Request URL: /osp/a/idm/auth/oauth2/authcodecontinue
Query String: privateId=8f5a5054e13cf33cff32&client_id=rbpm&irdpkg=1539116433947--1291448215
Scheme: http
Context Path: /osp
Servlet Path: /a
Path Info: /idm/auth/oauth2/authcodecontinue
Server Name: idmdesa.bbva.com
Server Port: 8080
Locale: es_AR
Host IP Address: 10.1.23.17
Remote Client IP Address: 10.1.23.50
Cookies
(1 of 4): JSESSIONID=B381FCBB49120870D5AB9750F8598CEB
(2 of 4): x-oidp-oauth2-1539116433905--846542199=9TC8P@z5t8Gq6etz3E@TtXq2Ajaseg523bCPRrPlRfkjcykpWttj6kYJl7kuHH0FBVgGHmvT8XDf0lMAZj1SXfM673HiqjCFwOjHr0CE09IyLaWcrQXUkf07G6Z03TSYJXVA/cW/6wOGoo27u/zKcYQO1BNbe9E/NRDIVFefleclEMekA/dNfZukok4a50XAnYAgvc/1f6Z1xD99gr2b9X6JTDYqEUoMDCKGfX6vaZPO10wfZ13H1tCjXrbpoxrvHdw12@PtEbb9AghGNlB8UWFK9sYXegsjFRPFopYSWpLab5FcLmlW6Bj@ficVjwFfvjLbmji@Z9AYowZZOgIus1iD8/OcSu1IzKtADVqRZRDHdLrne1dj4PG0I/wldXwRwT23HvW/LmBxaSmUMcptPg~~
(3 of 4): x-oidp-session59303d34382c2d310=200-O4FKILKO6VKJQD4RTIO6ZDAOFXJMOP66RJPL+H7K-580F1769-85BF!1!85C0!120!127!qARwZQb/yjuooYA0+vevExO/1R+e12Rkg11jjwnsBfc~!yW5pYeyHII6hGUPekPOeabVyLQKzRf2ofZ/mglyVF2EeYimN4JhbNQZbAx1iOnUvVdMrVguf5axIEyuEnedhjFCrutfihgreYWIV0NuNWU/KVYx/hNZP6IxjIJ0kDUuwgg4AKDlbK7Y0HzO86VXy/IIcniw8Mxv2YfXwf0ZcBH3IWqZo7yZyy1LwrtRHsmDaoI46q+ypdJzikdo7QV9T+1CSiilVWHK3EdSgPEaqq3UsFJb1u8WyZuQRSt/VDSdVZAEqng0YKTeXOFoaGQ8CR0IP/v40usstEmFryVRVLeOpyBpUDEKJ6spnG1NW3TJ0DhEREtKqVzVCJM6iSAL+HnasqqXtQijfjfs5wdPBhR448WvBKRrqAldqgf5+VaCn0T1HvLrKo7pqh+mzHzAhT+ykqK+A6AZaydfXU9xtFWIHYbAnYkUAajxpyleqdtfDS9DG72gU49kP3amOAXi9r0+DLMmhV2BeO2DCpV2lIHqIb9ecmmL1u0G65CJci+a1esvRUUEbuaykJ4yF+9bqkwz1cOfkCVVaWgEU7TEDgw37ebJMIPrOSm2wnBmwPJiePsS8QoarYxnBOOw0En6nDyRqgS1QkZDPJIQlMx7l6YtRxxm+j3Eo/1k73b+o+E8e9BLD1UWwlJXeHn8XAIvr8VVbcYsG+WgeLF9+uK75sRYDEhQJJSfT9kuC6//WFi0pbb1p5xeF1Qrc5CmsAfCTg2Azn7+jPBUjZiPgejMl57TrRF3qBi2UNvG7oL96rhRXUavxYPTjabCGZNC/eNr7g0k/C+IGMvVhTBSa8Xky9utCLhDO/xaDF3XpoVSkJq7Ypb4GgSm8xma+Ji9VeYvMbpDMXN6X5X1ny7DxnmztS9wLqUkahhNJPe5nZazDPEOIL/Ls7lOxpAAuATmY4mkAj/qGNAib+X6nNOeSllEcVrirkxOCuNiLkW/BS3ixbUah2/FfSQkTMBVhGj3ogyTMEECD1D8yAT0qnNlJ7c+xnZlnBq9WGbhLlzEHYuEu5HYOkXfxa40XCjJf1WG9rY303Uuiikg/ogvk3hfuVRIWfyraGHwhmMwCJLdUleH63GYekRjAxDLCeVVsEiSWHeQrGfUj0769yV7m9TPl2yNMYKWWLLP3a94qkACzfoeAjrOfJPJusfagVPaC0JaU/MlRUwfoiWeyIYjmmMRENivXG4d6Yr7mcWAhWWTzOvwjzPQFkZ7ya0dMFk6HcczbpBf8ig~~
(4 of 4): x-oidp-oauth2-1539116433947--1291448215=9TC8P@z5t8Gq6etz3E@Ttfl18gGcUat7gVbJNy@/PacxWuZsDCvtrZmk1OjJnuZUdMTm1/5g6sLrmozVKVqxMfM673HiqjCFwOjHr0CE09IyLaWcrQXUkf07G6Z03TSYJXVA/cW/6wOGoo27u/zKcYQO1BNbe9E/NRDIVFefleclEMekA/dNfZukok4a50XAnYAgvc/1f6Z1xD99gr2b9X6JTDYqEUoMDCKGfX6vaZPO10wfZ13H1tCjXrbpoxrvHdw12@PtEbb9AghGNlB8UWFK9sYXegsjFRPFopYSWpLab5FcLmlW6Bj@ficVjwFfvjLbmji@Z9AYowZZOgIus1iD8/OcSu1IzKtADVqRZRDHdLrne1dj4PG0I/wldXwRwT23HvW/LmBxaSmUMcptPg~~
Headers
accept=*/*
accept-language=es-AR
user-agent=Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; WOW64; Trident/7.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C)
accept-encoding=gzip, deflate
host=idmdesa.bbva.com:8080
cookie=(see above)
connection=Keep-Alive
authorization=Negotiate YIINXwYGKwYBBQUCoIINUzCCDU+gMDAuBgkqhkiC9xIBAgIGCSqGSIb3EgECAgYKKwYBBAGCNwICHgYKKwYBBAGCNwICCqKCDRkEgg0VYIINEQYJKoZIhvcSAQICAQBugg0AMIIM/KADAgEFoQMCAQ6iBwMFACAAAACjggU0YYIFMDCCBSygAwIBBaETGxFCRi5BUkcuSUdSVVBPQkJWQaIjMCGgAwIBAqEaMBgbBEhUVFAbEGlkbWRlc2EuYmJ2YS5jb22jggTpMIIE5aADAgEXoQMCAQSiggTXBIIE07og+HB6WfEWIaVm+6TLkcZdbcOomU/0J6VsUQx79S+ZnS+36s2m6ZsRuyh/JbgnSqY3f/iDfvy2oK7UuCPaVSVo1SUkQonT0RmeBu9h396MZdasrK+TB+Wtfb/70cBFjc4KoicyWu5yGhNiSjKPNHH8GSh8eEkxYzh57jy+6fZQ7BfQSA8NVbQWX3oh21Xb3Y/Yml4JdIuukbYVNqQllxk2ZRXDRC4bzZsy3k7Tjw8eyo4+m5R7bab8LFaTqIZxQ1f+1ndn9wB5PImedP6hlwMypS/HWQqP0K4vwR+0RkyQhenEPESj1DvYkY7uUsKOgtK+nBy2am6FOEq3BuMdMUeKekKlDXMLPz1PjjBkKYCrSO51X6hcPlpBbnMxuz8mN0CjI1J5L39NQBZAjAgUCURLG21PMctYuJN0XO/8jSyRmsbf48qyRc3t8PezdlJlHPmoBzXcWStoP53UL0iAHY2nfABPWjo8WAzXX5I2zaZr9a3eHqknBytbMI7l6sgIPyp5QiPs00nb79fgamzVtwKbH09YkHprAOBKnVFfssJyxNqo+iTSu+3m/zzgm3XB4xL+Wcm32yK/jwEa8gM19WoQwB5GBX5vPkYNduWOrRmGWyeoWg0dllfW2M7ulKZRuLqvY52CFN2tFXME05uFejdz+JIbSQ3SrvBP4wi8LqUXMGlzoYVgQDrckYbxzkuVYJjsX5SfdjfVCu+hgam+kRjW4PjA9ewY96/o1uTtWFLXxiWAZclEBqInp8uC7YhE1/sM02eKP1cBYiBOrAOGgKjnrrFGAAl3RWaDbJZ2791xINzKrzJV5hsbz9v+4bgv2281h0iWmMUkzVssFImBTnLRHDCCKsUjgRBUuuAzclPTWXpU7wZRjEAflbsHsvaNmpibEgyrc34eWIAqc4E2nQLkW98XHAuDqKsj/Nq2zDoRjNw7tGumwwRO8pQihMKTFhkfeNcqQcFje4E1b6KaBX7QkQspBuHvzpoehGCIHCeBXR17e+dx8VCICHqWgYjr4OaruXr+9ZSRAXvBhOnMUpIErVQRhVJH82RVoJUSjkf2qCN+7iwpg9O/xQZ/syI+ExW2/EIQLbs4MtCRUYRyHd7xdXgHVSz+O3aqShERwak7UYxBMawueeyDF+h5AMOhyVgDZpAjYetmI8GhAw4jTpFwAW58/CxOOuq49q3H+ouypptq5+iEiP4G8fevkXZWZtlMyYcceE5If/nUrYuPS3zer5eil5ZpZwkFc722aM+AXnK9Bvclmpi8qFX97YOwV1v98qxKYHTxVgKYcpWFDUbt3aWskr5zJMOUHhWqdiEDvIbTpgl/tw2nY9ELx2NMvDMPXRQac0m2uUzdQkavQ7ojkez7p2JhZDp49flW/YgmOggkOZPwUaf+04YKgnULlNiFK1NDImduJLzr7YjutTyziNuLl2/tKPgUL0eQz+40AwUCq2rIeTzf1kCBTPmI3OFK8L5tVpoJRMZSZNXh8JMk/DBKfJv46oZxlm9NPZzcCO1zCV1xeWwmNMVOepKvfRsZotZZ+2vywN92MQDZlY/tUZIZqIPA1B+G3kjMgwNjvQOpAYFZ0GIYceze/UtE1aap+l8jDdh19EPZouw2iDecaetxk7oTB5Gvcoxs/01SgyOapIIHrTCCB6mgAwIBF6KCB6AEggecGutXWWhGOoEOyxoCPc97TMNG5wrKJ9uP0df1sYWgFV8rSbF/LGg3yzJvpBc+BMQr/jeNBHMbWz3GFg9tbttw5LY0ojGOi6+xZqIgQ3dGZKh27KOPRmsIO+YW+wEo4lkURsH9wIypNAONEvhc7eBKWZscFSSxBudf365naU6rmKuNhwlEkQwqPAYQ4KPTjYcWKKKyIZd96aZmwkfMToFLnQ65QgrUGQolRyjFFuc4MD752oEx7ZxVG9zVqqM8K+FWO+vbqB3qdzxcIHXqCotjE+OHdyzK10pljDa8aEnGM8tQEFpuFXnFfu/bTkrq25WCvh/JiEaoQbJom3sQoMV6aCEQRB6llVmj9+is0A1ZOPu+tuvFphDUv/3gs9d7CKxNsdYK+XfMyasIt8WJdWPtNpXzyC/8FpEysSgk4XJhTEN8L22X6/C9xTxDHPOyKFxqvyOfc361FRGigd/gxQ5uDsoCLzltuMD7T/ql9tBdyvsgu/HxZl+zXOyq01FZLzZj/0YOwLy3LH3ZieESI+kH8xq2DWyymSOf2OiI8OKy6hq8yX1vTAIkcq89YUHcScw13bGundHTrbk1jY/YJ3PwDCbb4G8UmsRMmmYQB5JKadS9gxkBcFclRA5MHJjVEfsk5ixm2CU5IQku1cdZMABZHupSupl4N/zzxRk/il6UIvGfcDwBX9p87bkOvFjEZaSG2VXU9X8lxTlQJh1WTa8Q9SKnGXH0BgIqhyhPPs+XNQFHY1B/Oa82OGiiUgiw7gdXdi5z22kKgZsmuH2LiPd/qdyV8DMjrBk5d1Jb4gWddfNhN0IM/8JmV+4OYmaC6pNgeK/or6zRC++zD8hPg8iHqJtMkND+OZHkMWqDMUfKxCwkNryg4iwPD6csQeiIj+yDJcK3nQfimY2j9MrCaTloQZgoESEKo+MDi6mwKI2L1JYnBYfupwTbfF/AFhjAClrLtrWnRH51+5HaB7VvKqRfYkeufbZxlIk8yXZzbNNhlSDXpVzVMtEjCIttyJLCLGd6StWpWaTYBS8CitzG3lnf4nGHBKp/F8pJy9Y2pg62uSWBI8xDxb3IZxOiNi7HM/xcG/TAcyEfQwjARII8xU0KuM/e4+Eo7M3cTElGHHnJ3JHBTXMVfqpwngx6dH5ST2sNHdcG2O/YbOiZvQyVyNP112NpmHu/RNU1HcnLuBXMWKaDsDF17O0qnFv+VX69tz9Oz+lVBzb8sZG6bjNa9Ge0b0VvHyYgKf9JuPgblBuApN8P8RU+lTRwTDGW9EDF17JDzbVvN77rb+kCJ0jM90e1RfPhfXnIARy7gZsow/iwQ+jpCW3LdyoYusdHCihUanJ+QmGAOl9rdFzhAllavMslJ3y1SV87tuC/XuelrtHUa0ZfoKmbUDggzuDcGGhaD7Db7xwwaSPNlhs3QT2vevfuAHAkzhSUML9xp14JpRdmGZNfbwM2KmiV3wv7p7sOI2zWj4Pe2pyyO36/OQn9Mk5dlgU2bnnTDDB+T8QGl//uAVH7peyjtO/lT6tVPsmf6VMt8uW45GV1hTw6jsNAArEfw1F0yIObCHFKzrhCLeQPXqNRi1QpFdKxKLs1G//IEST8bgVFvvWuX2KkgiCdKp9ewlgZA4EzoTX6fzHzKB/6dDeNzYKT879YRCVVDouPN3Ben005tRYW+KyIfRVqgQ8oFHFzxZZLUU48iatBbuu2oogM2ndeNTl60sFnhN/Q9cuJ9pP5sQI3aFqTiSQZVjmk5Sf8SUNDACRAlpWiemB39tcRiCs6U8jhv5V1Jjrs5NYivfbvO5CHL1fLmzD9lGV59sM/kXNMdM5rKjb9gUVPhchibwCgK8Xm5rowBRBfd1uJE/UFS8fbwNmlWTGbJ+POdIqPQ87QwuUq+tBS4JqXk/v4d1FfLKp2+lBUSvKTmTwVH+v3KdjMkDXJdl0coyxa/B18PB1//2WjxYNN4kOKhxbki5rdB1WyTiNWO8/SwEPxJvO9xXGsPHXu6kB+mhSaP6EXXp3fkxZPI3n64eO1dPEijcwgSgCx2nOievy0yFsZvF7cKReQN/FH7Grcc4uBuBEDjl5NiKa0m07T6T7unu9hMsuTtlw8iVt1mJ1Wwv1oPGkF1ky3z7H1uGFQxm2zYFZHkd/V5RTAKusjxhxwrdaPMkPo7scBzyDW4fK8fOOBT4cUX/EmMAJvUHdz+M3VqvKYye8CHj87eQ5hNjUZPps1l2/z/XcJTLgXU71pJHqVJ/QYqhRwHV74Ysm3VDAXaKgRI/RWPT0jOB+/SSnpmp+XpSW7t8qhdZS5HNcRGxSU7uONVwtbsE7q18aCDjaxfEIlwG7lpRpKMw3psKEwoHNS9VhvFb5Ho9BdJKWq+2Q+alU4/Tw8KFTisnwnql8dHFdFn842xKauqHoipojyGt3zNTWM1qgnkKn9dpatWB/Q7UU/49qdwH6XNP1c3fKEOyupGzapCnipwfxrC32GL779mmDElhw+qspvlpPvlSIOhjrcpc4L5/Nrzaafnaweq2K3HFH4AeuWcCQSMSBU9C30QeheamDSgTZWPaD9nLerBiHBVBhqbAxyDndi2TV58P/OJU4WFdsWFZ9faQ==
dnt=1
Session
Id: B381FCBB49120870D5AB9750F8598CEB
Last Accessed Time: 2018-10-09T17:20:34.243-0300 (1539116434243)
Parameters
privateId
client_id
irdpkg
Attributes
OSPRequestContext

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.servlet.OSPServlet.process() [213] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.262-0300
Log Data:
Class: OSPRequestContext
HttpServletResponse exists.
Http request type: GET
Request number: 11
Tenant: For IDM and IG
Service: For IDM and IG(id=auth)
Path element count: 2
Element: oauth2
Element: authcodecontinue
Override locale: es_AR

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.servlets.handler.AuthenticationServiceRequestHandler.resolveHandler() [187] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.263-0300
Log Data: IDP oauth2 handler to process request received for authcodecontinue

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.authentication.NIDPAuthentication.addAuthnContext() [361] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.264-0300
Log Data: Class: NIDPLocalAuthentication
Identity Id: 9d26afd47be49549bb839d26afd47be4
Display Text: krb-contract-$default-card$
Consumed: true
AuthnContext Objects:
Class: NIDPAuthnContext
Auth instant: 2018-10-09T17:20:34.194-0300 (1539116434194), elapsed: 0.070s (70)
Last used time: 2018-10-09T17:20:34.237-0300 (1539116434237), elapsed: 0.027s (27)
Authentication types: Kerberos
Mag Context: false
Class: AuthenticationContract
Id: krb-contract
Name: User Kerberos Login
URI: idm:login:user:kerberos
Trust Level: 0
Timeout: 0
Check Trust Level: false
Show Pwd Expired UI: true
Remote: false
Default: true
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Executable: (Auto) Kerberos Principal Mapping Method(id={$auto}-krb-mapping-method)
Executable: (Auto) IDM Admin Role Mapping Method(id={$auto}-admin-role-mapping-method)
Authentication Card: User Kerberos Login-$default-card$(id=krb-contract-$default-card$)

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.profile.authentication.MethodProfile.setExecutables() [270] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.265-0300
Log Data: Number of contract executables set to run: 3

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.session.NIDPSession.setAuthPrincipal() [1426] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.265-0300
Elapsed time: 32.147 microseconds
Log Data: Setting the authenticated principal:
Candidate principal:
Type: LDAPPrincipal
GUID: 9d26afd47be49549bb839d26afd47be4
User identifier: cn=A100169,ou=People,ou=Accounts,o=Meta
Authentication source: bisadus
Cached attribute count: 0
Existing principal found:
Type: LDAPPrincipal
GUID: 9d26afd47be49549bb839d26afd47be4
User identifier: cn=A100169,ou=People,ou=Accounts,o=Meta
Authentication source: bisadus
Cached attribute count: 0
Candidate principal cached but not added to session: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.<init>() [456] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.265-0300
Log Data: Built Session from XML: id: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX, Type: PERSISTENT

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.reapSessionData() [795] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.265-0300
Elapsed time: 6.249 microseconds
Log Data: Clean up expired session data instances:
No expired instances found.

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.session.NIDPSession.isAuthenticated() [2585] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.265-0300
Elapsed time: 33.226 microseconds
Log Data: Session authenticated?
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894
Initial consumed authentications count: 1
The local authentication has at least one existing AuthnContext
Local: true
Remote: false
Authenticated: true

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.cluster.ClusterCookieContext.resolveSession() [153] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.265-0300
Elapsed time: 258.756 microseconds
Log Data:
Session cached:
Class: NIDPSession
Identifier: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Sub-identifier: 0
Private identifier: )u866t5WHO9Hne32*6Y%9hR]N
Type: PERSISTANT
Create time: 2018-10-09T17:20:33.904-0300 (1539116433904), elapsed: 0.362s (362)
Last used time: 2018-10-09T17:20:34.237-0300 (1539116434237), elapsed: 0.029s (29)
Main JSP: main
Set activity: true
Storage cache: idm_idv=af7b7657-fa2e-4dc3-ab00-fae44006d6a6
Session data key: 1
Class: NIDPSessionData
Id: 1
Create time: 2018-10-09T17:20:33.905-0300 (1539116433905), elapsed: 0.361s (361)
Target stack:
0: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=354f2b357f2aacae1d48&client_id=rbpm&irdpkg=1539116433905--846542199
Class: ContractExecutionProfile
Service: For IDM and IG(id=auth)
Request: /osp/a/idm/auth/oauth2/authcodecontinue
Reset: false
First Time: true
Passive: false
Force: false
Counter: 0
Return URL: http://idmdesa.bbva.com:8080/osp/a/idm/auth/app/login?acAuthCardId=krb-contract-%24default-card%24&sid=1
Top: false
Authenticated: false
Credential Update: false
Class: AuthenticationContract
Id: krb-contract
Name: User Kerberos Login
URI: idm:login:user:kerberos
Trust Level: 0
Timeout: 0
Check Trust Level: false
Show Pwd Expired UI: true
Remote: false
Default: true
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Executable: (Auto) Kerberos Principal Mapping Method(id={$auto}-krb-mapping-method)
Executable: (Auto) IDM Admin Role Mapping Method(id={$auto}-admin-role-mapping-method)
Authentication Card: User Kerberos Login-$default-card$(id=krb-contract-$default-card$)
Session data key: 2
Class: NIDPSessionData
Id: 2
Create time: 2018-10-09T17:20:33.947-0300 (1539116433947), elapsed: 0.319s (319)
Target stack:
0: http://idmdesa.bbva.com:8080/osp/a/idm/auth/oauth2/authcodecontinue?privateId=8f5a5054e13cf33cff32&client_id=rbpm&irdpkg=1539116433947--1291448215
Logout flag: 0
Show logout: false
Class: LDAPPrincipal
GUID: 9d26afd47be49549bb839d26afd47be4
Auth Source Id: bisadus
Result of getLogIdentifier(): cn=A100169,ou=People,ou=Accounts,o=Meta
Result of getUserIdentifier(): cn=A100169,ou=People,ou=Accounts,o=Meta
Provided Identities: 0
Consumed Identities: 1
Lookup Key: local
Persistent:
<NIDPIdentity(null)>:
Identifier: 9d26afd47be49549bb839d26afd47be4
Format: federated
Name Qualifier: local
SP Name Qualifier: local
Provider: local
Cluster DN: bisadus
GUID: 9d26afd47be49549bb839d26afd47be4
IsTemporary?: false
IsAffiliation: false
Provisioned: false
Cachable: true
Result of getIdentityID(): local
DN: cn=A100169,ou=People,ou=Accounts,o=Meta
Class: NIDPConsumedAuthentications
[Empty or Null List]
Refresh Index: -2
Last Refresh Time: 0
Class: NIDPLocalAuthentication
Identity Id: 9d26afd47be49549bb839d26afd47be4
Display Text: krb-contract-$default-card$
Consumed: true
AuthnContext Objects:
Class: NIDPAuthnContext
Auth instant: 2018-10-09T17:20:34.194-0300 (1539116434194), elapsed: 0.072s (72)
Last used time: 2018-10-09T17:20:34.237-0300 (1539116434237), elapsed: 0.029s (29)
Authentication types: Kerberos
Mag Context: false
Class: AuthenticationContract
Id: krb-contract
Name: User Kerberos Login
URI: idm:login:user:kerberos
Trust Level: 0
Timeout: 0
Check Trust Level: false
Show Pwd Expired UI: true
Remote: false
Default: true
Executable: (Auto) Kerberos Authentication Method(id={$auto}-krb-auth-method)
Executable: (Auto) Kerberos Principal Mapping Method(id={$auto}-krb-mapping-method)
Executable: (Auto) IDM Admin Role Mapping Method(id={$auto}-admin-role-mapping-method)
Authentication Card: User Kerberos Login-$default-card$(id=krb-contract-$default-card$)
Class: NIDPProvidedAuthentications
[Empty or Null List]

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.session.NIDPSession.getSessionData() [734] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.266-0300
Elapsed time: 14.720 microseconds
Log Data: Get session data based on request:
Creating new session data; id: 3

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.oauth2.handler.InterRequestPackage.<init>() [265] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.266-0300
Elapsed time: 215.474 microseconds
Log Data: Inter-request data:
Package Id: 1539116433947--1291448215
Searching for cookie: x-oidp-oauth2-1539116433947--1291448215
Total request cookies: 4
Found.
Length: 408
Base64-decoded byte count: 304
Decrypted cookie byte count: 300
Plaintext cookie length: 300

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.oauth2.handler.AuthCodeHandlerBase.issueAuthMaterials() [183] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.267-0300
Log Data: Redirecting back to client with authorization code: http://idmdesa.bbva.com:8080/IDMProv/oauth?code=eHwAIEDoqrCbEhlgAVE/LzsUYIlzILEIOpgD3rImJtzwIAMQrF9KGqKrLP4KWR6LqkcXeRrhiHv6H3xT4J3u3JPVBnkFremTsKNC5P3UM%40SPRXZUw5BldVcr/N/SStPlebwcj%40kw1MPyEswENHHiHPW7RyG3MAsrXYOnddDlI/tbFDsy553%40Knl6WcO/bxOy0YN6UhI4MPukQq79TZll2FZkoHxfWlCnZ%40dKEyB5qOyDLOhI08S/tX8wmpeGSW9PEO//XU4D1DsR7aipoH0YMgHZCwUYrMT4Og/tT47l3S%40qPvveh/vvcGrY0Vi4SVHb%40HJ2cOAbwuBKUPrbMt5eUOu/de/th5isHZiEutv7ibg%40pVLa&state=b22b4ca3-e31b-4143-a9ab-7be28030f479

Preamble: [OIDP]
Priority Level: INFO
Java: internal.osp.oidp.service.oauth2.handler.TokenRequestHandlerBase.auditTokenCreation() [385] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.267-0300
Log Data: IssueOAuthCode

Preamble: [OIDP]
Priority Level: FINEST
Java: internal.osp.oidp.service.oauth2.handler.InterRequestPackage.cleanup() [347] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.307-0300
Elapsed time: 114.747 microseconds
Log Data: Deleting OAuth2 Inter-request data package cookie: 1539116433947--1291448215
Setting cookie:
Name: x-oidp-oauth2-1539116433947--1291448215
Domain: idmdesa.bbva.com
Path: /
Maximum age (seconds): 0
Secure: false
HttpOnly: true

Preamble: [OIDP]
Priority Level: FINER
Java: internal.osp.oidp.service.servlets.handler.AuthenticationServiceRequestHandler.commit() [535] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.308-0300
Elapsed time: 2.998 milliseconds
Log Data: Persisting session: d44d8ba9c00d461cbc48ec1b3fb7db7a-fc959891d19d898894-CX
Session to cookie: true

Preamble: [OSP]
Priority Level: FINEST
Java: internal.osp.framework.UIResponder$Response.setResponse() [1388] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.311-0300
Log Data: Response: TARGET
Target: http://idmdesa.bbva.com:8080/IDMProv/oauth?code=eHwAIEDoqrCbEhlgAVE/LzsUYIlzILEIOpgD3rImJtzwIAMQrF9KGqKrLP4KWR6LqkcXeRrhiHv6H3xT4J3u3JPVBnkFremTsKNC5P3UM%40SPRXZUw5BldVcr/N/SStPlebwcj%40kw1MPyEswENHHiHPW7RyG3MAsrXYOnddDlI/tbFDsy553%40Knl6WcO/bxOy0YN6UhI4MPukQq79TZll2FZkoHxfWlCnZ%40dKEyB5qOyDLOhI08S/tX8wmpeGSW9PEO//XU4D1DsR7aipoH0YMgHZCwUYrMT4Og/tT47l3S%40qPvveh/vvcGrY0Vi4SVHb%40HJ2cOAbwuBKUPrbMt5eUOu/de/th5isHZiEutv7ibg%40pVLa&state=b22b4ca3-e31b-4143-a9ab-7be28030f479
Headers:
Cache-Control
Pragma

Preamble: [OSP]
Priority Level: FINER
Java: internal.osp.common.logging.HttpResponseLogger.log() [138] thread=http-nio-8080-exec-9
Time: 2018-10-09T17:20:34.312-0300
Log Data: HttpServletResponse (Number 11)
Duration (seconds): 0.53
Character encoding: ISO-8859-1
Locale: en
Buffer size: 8192

Priority Level: INFO
Java: internal.atlaslite.jcce.ldap.jndi.JNDIConnection.close() [2235] thread=JCCE JNDI Connection Retirement
Time: 2018-10-09T17:20:35.449-0300
Log Data: Close Conn: cId: a5ac7c8d-df30-41cc-98dc-be1f34671ead


Any ideas on how we can continue troubleshooting this issue?

Thanks in advance
Labels (1)
0 Likes
4 Replies
Knowledge Partner
Knowledge Partner

Re: Timeout after login with Kerberos SSO

On 2018-10-09 22:34, mmarchese wrote:
> Any ideas on how we can continue troubleshooting this issue?
>
> Thanks in advance

I've never seen that error.
Some things you can begin to check:

* On the SPN account in AD, make sure that "This account supports
Kerberos AES 128 bit encryption" and his account supports Kerberos AES
256 bit encryption" is checked.

* You can try to set "Trust this user for delegation to any service" on
the Delegation tab in ADUC

* Time sync.

--
If you find this post helpful and are logged into the web interface,
show your appreciation and click on the star below.
0 Likes
Micro Focus Expert
Micro Focus Expert

Re: Timeout after login with Kerberos SSO

On 2018-10-09 23:21, alekz wrote:
> * On the SPN account in AD, make sure that "This account supports
> Kerberos AES 128 bit encryption" and his account supports Kerberos AES
> 256 bit encryption" is checked.


You'll also need to install the 'Java Cryptography Extension (JCE)
Unlimited Strength Jurisdiction Policy Files' to support such key types.

--
Norbert
--
Norbert
0 Likes
Knowledge Partner
Knowledge Partner

Re: Timeout after login with Kerberos SSO

On 2018-10-10 09:53, Norbert Klasen wrote:
> On 2018-10-09 23:21, alekz wrote:
>> * On the SPN account in AD, make sure that "This account supports
>> Kerberos AES 128 bit encryption" and his account supports Kerberos AES
>> 256 bit encryption" is checked.

>
> You'll also need to install the 'Java Cryptography Extension (JCE)
> Unlimited Strength Jurisdiction Policy Files' to support such key types.
>

Yes, that is correct.
Later versions have that enabled by default according to Oracle:
"Enabled unlimited cryptographic policy by default."
https://www.java.com/en/jre-jdk-cryptoroadmap.html

--
If you find this post helpful and are logged into the web interface,
show your appreciation and click on the star below.
0 Likes
mmarchese Absent Member.
Absent Member.

Re: Timeout after login with Kerberos SSO

Thanks for your replies.

Unlimited Strength Jurisdiction Policy Files are enabled by default as alekz said.

Also,

I added the

"This account supports Kerberos AES 128 bit encryption"
"This account supports Kerberos AES 256 bit encryption"

options for the SPN user. ("Trust this user for delegation to any service" was already enabled).

I think we'll end up opening an SR on this issue.
0 Likes
The opinions expressed above are the personal opinions of the authors, not of Micro Focus. By using this site, you accept the Terms of Use and Rules of Participation. Certain versions of content ("Material") accessible here may contain branding from Hewlett-Packard Company (now HP Inc.) and Hewlett Packard Enterprise Company. As of September 1, 2017, the Material is now offered by Micro Focus, a separately owned and operated company. Any reference to the HP and Hewlett Packard Enterprise/HPE marks is historical in nature, and the HP and Hewlett Packard Enterprise/HPE marks are the property of their respective owners.