Getting datastore exception messages accessing Access Gateway or Policy general tabs

  • 7015150
  • 06-Jun-2014
  • 06-Jun-2014

Environment

NetIQ Access Manager 3.2
NetIQ Access Manager 4.0
NetIQ Access Manager Admin Console
IE8 and IE11 browser accessing iManager Admin COnsole

Situation

After applying 3.2 SP2, administrator randomly started seeing the following popup error when browsing the policy tab, and some Access Gateway configuration fields:

'Error connecting to the datastore'

Although not always able to dup the issue 100% of the time, the following steps did reproduce it about 30% of the time:

a) admin logs into iManager
b) admin selects devices -> access gateways. This triggers the request to 'GET /roma/jsp/admin/appliance/appliancelist.jsp?appfilter=ag'
c) admin randomly gets an exception popping up on browser with 'Error connecting to the datastore'

Based on the Admin Console app_sc log file when the issue occurred, it looks like we fail to update an attribute that we are trying to write to in the config store. The exception in the app_sc log file does reference the problem connecting to the data store as shown below:
397758(D)2013-12-16T19:07:37Z(L)application.sc.core(T)20745(C)com.volera.vcdn.application.sc.core.VException(M)<init>(E)javax.naming.ServiceUnavailableException:
[LDAP: error code 51 - NDS error: already in use (-166)]; remaining name ''
 at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3152)
 at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3033)
 at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2840)
 at com.sun.jndi.ldap.LdapCtx.c_modifyAttributes(LdapCtx.java:1411)
 at
com.sun.jndi.toolkit.ctx.ComponentDirContext.p_modifyAttributes(ComponentDirContext.java:253)
 at
com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(PartialCompositeDirContext.java:165)
 at
com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(PartialCompositeDirContext.java:154)
 at com.volera.vcdn.application.sc.core.Info.setAttributeToNDS(y:2174)
 at com.volera.vcdn.application.sc.core.Info.setInfoAttributeValue(y:3488)
 at com.volera.vcdn.application.sc.core.DeviceManager.setMonitorData(y:672)
 at
com.volera.vcdn.application.sc.monitor.MonitorEventListener.eventOccurred(y:1972)
:
 at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
   at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
   at java.lang.Thread.run(Thread.java:722)
  (Msg)<amLogEntry> 2013-12-16T14:07:37Z SEVERE DeviceManager: AM#100905083:
Error connecting to the datastore. </amLogEntry>

Looking at the dstrace output on the Admin Console, homing in on the problem timestamp from the app_sc log 
file above, we found the exact operation that was causing the issue: [2013/12/16 14:07:37.691] (134.216.176.147:50558)(0x228f2:0x66) DoModify on connection 0xe15a000 [2013/12/16 14:07:37.691] (134.216.176.147:50558)(0x228f2:0x66) modify: dn (ou=ag-06D81183467DE42C,ou=AppliancesContainer,ou=Partition,ou=PartitionsContainer,ou=VCDN_Root,ou=accessManagerContainer,o=novell) [2013/12/16 14:07:37.691] (134.216.176.147:50558)(0x228f2:0x66) modifications: [2013/12/16 14:07:37.692] (134.216.176.147:50558)(0x228f2:0x66) replace: romaEXMonitoringXMLDoc [2013/12/16 14:07:37.692] (134.216.176.147:50558)(0x228f2:0x66) DDCModifyEntry failed, err = already in use (-166) [2013/12/16 14:07:37.692] (134.216.176.147:50558)(0x228f2:0x66) Sending operation result 51:"":"NDS error: already in use (-166)" to connection 0xe15a000 [2013/12/16 14:07:37.718] (134.216.176.147:50536)(0x31143:0x63) DoSearch on connection 0xdecf880 [2013/12/16 14:07:37.718] (134.216.176.147:50536)(0x31143:0x63) Search request: base: "ou=AppliancesContainer,ou=Partition,ou=PartitionsContainer,ou=VCDN_Root,ou=accessManagerContainer,o=novell" scope:0 dereference:0 sizelimit:0 timelimit:0 attrsonly:0 filter: "(objectClass=*)" no attributes [2013/12/16 14:07:37.718] (134.216.176.147:50536)(0x31143:0x63) Empty attribute list implies all user attributes Basically, what is happening here is that the AG was updating the RomaEXMonitoringXMLDoc attribute (with stats info) when it was alread in use. The eDir API failed because eDir errors out, and we throw the exception as a result.

Resolution

Apply 4.0 SP1 patch.

Cause

There's a deadlock issue on an existing LDAP connecton. The fix creates a new ldap connection for 
the write operation and then closes after using it.