OAM/EBS Logins Fail the First Time for OID Users Sync'd from AD | OAM log error: OAMSSA-20023: Authentication Failure for user : user01, for idstore EBSIdStore with exception invalid username/password with primary error message null (Doc ID 1903188.1)

Last updated on MARCH 08, 2017

Applies to:

Oracle Internet Directory - Version 10.2.1.0 and later
Oracle Access Manager - Version 11.1.2.0.0 to 11.1.2.0.0 [Release 11g]
Information in this document applies to any platform.

Symptoms

Oracle Internet Directory (OID) 11g integrated with Microsoft Active Directory (MS AD) (using External Authentication Plugins) and Oracle Access Manager (OAM) with EBusiness Suite (EBS).

EBS/OAM logins for user synchronized from AD to OID work consistently and fast on one OAM/OID environment but not on another.

The first time, the login returns a message that the SSO login is not in sync with EBS and prompts to enter the EBS password.

After that, a subsequent login retry no longer prompts for the password and the login succeeds.

Most (~99%) of the time, the login works on the second try.

The oam.log shows:

[2014-06-18T12:31:06.286-05:00] [oam_server1] [NOTIFICATION] [] [oracle.oam.engine.authn] [tid: [ACTIVE].ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'] [userId: ] [ecid: 4705ba953175939d:-5232e0dc:146ab5dce9b:-8000-0000000000000d72,0] [APP: oam_server#11.1.2.0.0] [[
oracle.security.am.engine.authn.api.exception.AuthenticationException
at oracle.security.am.engine.authn.internal.executor.AuthenticationModuleExecutor.checkAndThrowAuthenticationException(AuthenticationModuleExecutor.java:321)
at oracle.security.am.engine.authn.internal.executor.AuthenticationModuleExecutor.execute(AuthenticationModuleExecutor.java:242)
at oracle.security.am.engine.authn.internal.executor.AuthenticationSchemeExecutor.execute(AuthenticationSchemeExecutor.java:98)
...<etc>...
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:256)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)
Caused by: oracle.security.am.engines.common.identity.provider.exceptions.IdentityProviderException: OAMSSA-20023: Authentication Failure for user : user01, for idstore EBSIdStore with exception invalid username/password with primary error message null
at oracle.security.am.engines.common.identity.provider.impl.UserProviderImpl.authenticateUserByName(UserProviderImpl.java:1040)
at oracle.security.am.engines.common.identity.provider.impl.IdentityProviderImpl.authenticateUserByName(IdentityProviderImpl.java:911)
at oracle.security.am.engines.common.identity.provider.impl.OracleUserIdentityProvider.authenticateUserByName(OracleUserIdentityProvider.java:461)
at oracle.security.am.engine.authn.internal.executor.AuthenticationModuleExecutor.execute(AuthenticationModuleExecutor.java:212)
... 42 more
Caused by: oracle.security.idm.AuthenticationException: invalid username/password
at oracle.security.idm.providers.oid.OIDUserManager.authenticateUser(OIDUserManager.java:369)
at oracle.security.idm.providers.oid.OIDUserManager.authenticateUser(OIDUserManager.java:92)
at oracle.security.am.engines.common.identity.provider.impl.UserProviderImpl.authenticateUserByName(UserProviderImpl.java:1028)
... 45 more
]]


The corresponding (ecid) entries in the level 1 debug OID server log shows the ldapcompare operation succeeds (RESULT=6), but has a long delay (e.g., OPtime=8024000 micro sec):

[2014-06-18T12:31:04-05:00] [OID] [TRACE:16] [] [OIDLDAPD] [host: myoidhost] [pid: 4527] [tid: 9] [ecid: 4705ba953175939d:-5232e0dc:146ab5dce9b:-8000-0000000000000d72,0:3] ServerWorker (REG):[[
BEGIN
ConnID:116 mesgID:182 OpID:181 OpName:search ConnIP:::ffff: ConnDN:cn=orcladmin
orclinmemFilter:
  Orig Filter(numAVAFilters=2):(&(cn=user01)(objectclass=inetorgperson))
  Removed Filter: (objectclass=inetorgperson)
 New Filter(numAVAFilters=1):(cn=user01)

2014-06-18T12:31:04 * INFO :gslfseADoSearch BASE = cn=users,dc=mycompany,dc=com FILTER = (cn=user01) #REQDATTR = 7 SCOPE = 2 REQDATTRS = mail cn description orclguid objectclass displayname cn
 TIMELIMIT = 0 SIZELIMIT = 0 DEREF = 3
2014-06-18T12:31:04 * INFO:gsleswrASndResult OPtime=2867 micro sec RESULT=0 tag=101 nentries=1
END
]]
[2014-06-18T12:31:04-05:00] [OID] [TRACE:16] [] [OIDLDAPD] [host: myoidhost] [pid: 4527] [tid: 10] [ecid: 4705ba953175939d:-5232e0dc:146ab5dce9b:-8000-0000000000000d72,0:5] ServerWorker (REG):[[
BEGIN
ConnID:116 mesgID:183 OpID:182 OpName:compare ConnIP:::ffff: ConnDN:cn=orcladmin
gslfcmADoCompare: IP Address (::ffff:) dn (cn=user01,ou=user employees,ou=corp,cn=users,dc=mycompany,dc=com) attr (userpassword) value(******)
2014-06-18T12:31:12 * INFO:gsleswrASndResult OPtime=8024000 micro sec RESULT=6 tag=111 nentries=0
END
]]


Checking further ldapcompare operations in the OID log shows the OPtime values vary, for example:

2014-06-18T12:29:55 * INFO:gsleswrASndResult OPtime=8042413 micro sec RESULT=6 tag=111 nentries=0
2014-06-18T12:29:58 * INFO:gsleswrASndResult OPtime=16866 micro sec RESULT=6 tag=111 nentries=0
2014-06-18T12:30:23 * INFO:gsleswrASndResult OPtime=15188 micro sec RESULT=6 tag=111 nentries=0
2014-06-18T12:31:12 * INFO:gsleswrASndResult OPtime=8024000 micro sec RESULT=6 tag=111 nentries=0
2014-06-18T12:31:14 * INFO:gsleswrASndResult OPtime=17039 micro sec RESULT=6 tag=111 nentries=0


Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms