EM12c: OMS Restarts with Stuck Threads reported for LDAP Provider (Doc ID 2144989.1)

Last updated on JUNE 18, 2016

Applies to:

Enterprise Manager Base Platform - Version 12.1.0.1.0 and later
Information in this document applies to any platform.

Symptoms

12c OMS integrated with Active Directory. Frequent OMS restarts  are observed.

EMGC_OMS1.out shows entries similar to below entries:

EMGC_OMS1.out
=============
<May 13, 2016 12:41:08 PM EST> <Error> <WebLogicServer> <BEA-000337> <[STUCK] ExecuteThread: '14' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "662" seconds working on the request "Workmanager: default, Version: 0, Scheduled=true, Started=true, Started time: 662997 ms
[
POST /em/websvcs/emws/ConsoleJobStepExecutorService HTTP/1.1
Connection: TE
TE: trailers, deflate, gzip, compress
User-Agent: Oracle HTTPClient Version 10h
SOAPAction: ""
Accept-Encoding: gzip, x-gzip, compress, x-compress
ECID-Context: 1.0000LIbQHfJBx0Ipyo_AiW1NDHZO000002;lbDHasnE
Content-type: text/xml; charset=UTF-8
Content-Length: 1012

]", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
netscape.ldap.LDAPMessageQueue.waitForMessage(Unknown Source)
netscape.ldap.LDAPMessageQueue.waitFirstMessage(Unknown Source)
netscape.ldap.LDAPConnection.sendRequest(Unknown Source)
netscape.ldap.LDAPConnection.search(Unknown Source)
weblogic.security.providers.authentication.LDAPAtnDelegate.getDNForUser(LDAPAtnDelegate.java:3690)
weblogic.security.providers.authentication.LDAPAtnDelegate.authenticate(LDAPAtnDelegate.java:3533)
weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl.login(LDAPAtnLoginModuleImpl.java:227)
com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper.java:110)
java.security.AccessController.doPrivileged(Native Method)
com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper.java:106)
sun.reflect.GeneratedMethodAccessor418.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:597)
javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)
javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
java.security.AccessController.doPrivileged(Native Method)
javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
javax.security.auth.login.LoginContext.login(LoginContext.java:579)
com.bea.common.security.internal.service.JAASLoginServiceImpl.login(JAASLoginServiceImpl.java:113)
sun.reflect.GeneratedMethodAccessor643.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
....
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle got username from callbacks[0], UserName=SYSMAN>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <LDAP Atn Login username: SYSMAN>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <authenticate user:SYSMAN>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getConnection return conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getDNForUser search("OU=Users,OU=IDC,DC=idc,DC=oracle,DC=com", "(&(&(sAMAccountName=SYSMAN)(objectclass=user))(!(userAccountControl:1.2.840.113556.1.4.803:=2)))", base DN & below)>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <DN for user SYSMAN: null>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <returnConnection conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getConnection return conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getDNForUser search("OU=Users,OU=IDC,DC=idc,DC=oracle,DC=com", "(&(&(sAMAccountName=SYSMAN)(objectclass=user))(!(userAccountControl:1.2.840.113556.1.4.803:=2)))", base DN & below)>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <DN for user SYSMAN: null>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <returnConnection conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <javax.security.auth.login.FailedLoginException: [Security:090302]Authentication Failed: User SYSMAN denied
at weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl.login(LDAPAtnLoginModuleImpl.java:229)
at com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper.java:110)
at java.security.AccessController.doPrivileged(Native Method)
at com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper.java:106)
at sun.reflect.GeneratedMethodAccessor418.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
at com.bea.common.security.internal.service.JAASLoginServiceImpl.login(JAASLoginServiceImpl.java:113)
...
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getConnection return conn:LDAPConnection { ldapVersion:2 bindDN:""}>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getDNForUser search("ou=people,ou=myrealm,dc=GCDomain", "(&(uid=SYSMAN)(objectclass=person))", base DN & below)>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <DN for user SYSMAN: null>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <returnConnection conn:LDAPConnection { ldapVersion:2 bindDN:""}>
<May 13, 2016 10:05:50 PM EST> <Debug> <SecurityAtn> <BEA-000000> <javax.security.auth.login.FailedLoginException: [Security:090302]Authentication Failed: User SYSMAN denied
at weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl.login(LDAPAtnLoginModuleImpl.java:229)
at com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper.java:110)
at java.security.AccessController.doPrivileged(Native Method)
at com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper.java:106)
at sun.reflect.GeneratedMethodAccessor418.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)
...
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle got username from callbacks[0], UserName=SYSMAN>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <LDAP Atn Login username: SYSMAN>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <authenticate user:SYSMAN>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getConnection return conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getDNForUser search("OU=Users,OU=IDC,DC=idc,DC=oracle,DC=com", "(&(&(sAMAccountName=SYSMAN)(objectclass=user))(!(userAccountControl:1.2.840.113556.1.4.803:=2)))", base DN & below)>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <DN for user SYSMAN: null>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <returnConnection conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getConnection return conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <getDNForUser search("OU=Users,OU=IDC,DC=idc,DC=oracle,DC=com", "(&(&(sAMAccountName=SYSMAN)(objectclass=user))(!(userAccountControl:1.2.840.113556.1.4.803:=2)))", base DN & below)>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <DN for user SYSMAN: null>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <returnConnection conn:LDAPConnection {ldaps://myadserver.idc.oracle.com:636 ldapVersion:3 bindDN:"CN=oemadint,OU=Service Accounts,OU=IDC,DC=idc,DC=oracle,DC=com"}>
<May 13, 2016 10:06:07 PM EST> <Debug> <SecurityAtn> <BEA-000000> <javax.security.auth.login.FailedLoginException: [Security:090302]Authentication Failed: User SYSMAN denied
at weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl.login(LDAPAtnLoginModuleImpl.java:229)
at com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper.java:110)
at java.security.AccessController.doPrivileged(Native Method)
at com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper.java:106)
...
<May 13, 2016 10:07:01 PM EST> <Debug> <SecurityAtn> <BEA-000000> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) One or more PrincipalValidators handled this PrincipalClass, returning true>
<May 13, 2016 10:07:01 PM EST> <Debug> <SecurityAtn> <BEA-000000> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principals) validated all principals>
<May 13, 2016 10:07:22 PM> <FINEST> <NodeManager> <Waiting for the process to die: 25542>
<May 13, 2016 10:07:22 PM> <INFO> <NodeManager> <Server failed so attempting to restart (restart count = 1)>
<May 13, 2016 10:07:22 PM> <INFO> <NodeManager> <Starting WebLogic server with command line: /em/app/oracle/gc_inst/user_projects/domains/GCDomain/bin/startEMServer.sh >
<May 13, 2016 10:07:22 PM> <FINEST> <NodeManager> <Environment: EMHOME=/em/app/oracle/oms/oms>
<May 13, 2016 10:07:22 PM> <FINEST> <NodeManager> <Environment: EM_REPOS_USER=SYSMAN>
<May 13, 2016 10:07:22 PM> <FINEST> <NodeManager> <Environment:

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