Users having to submit credentials multiple times on login page before successfully logging into Identity Server

Access Manager setup with Linux Access Gateway (LAG) accelerating multiple protected resources. In most cases, the users can authenticate successfully at the Identity server (IDP) and get redirected back to the LAG to retrieve the protected resources. Randomly however, users must submit their credentials a few times at the IDP server before they are redirected back to the LAG protected resources. After submitting the credentials initially, they simply get the IDP login page again to resubmit. It sometimes takes 4 or 5 attempts before the IDP login page disappears and users get the page they are expecting.

Drop the idle timeout for LDAP connections to 10 seconds (from the user store configuration setup under IDP -> Local -> User Stores). The customers was set to 60 seconds ... the default is 10 seconds.

There seems to be an issue with the admin connections (used for ldap searches) to the LDAP AD user store. Reducing the idle timeout of ldap connection from 60 to 10 seconds in our configuration worked around this issue.

With the HTTP headers output from the browser and the IDP server's catalina.out file (with IDP component level logging set to DEBUG for APplication and Liberty), we could see the following:

- we would succeed on the 6th POST (search for 'Method: POST' string) attempt. The previous 5 POSTs have generated the 1528 error

<amLogEntry> 2011-05-25T15:16:51Z VERBOSE NIDS Application: LDAP search objects found: 0 </amLogEntry>
<amLogEntry> 2011-05-25T15:17:06Z VERBOSE NIDS Application: Authentication contract 'Name/Password - Form' failed in method 'Name/Password - Form' for session C9AC15E57C31B93CFBB333D5B493BCC0.  NIDPMAIN.1528ncashell </amLogEntry>

The LDAP LAN trace taken from the IDP server at this instant in time showed one set of LDAP search and bind requests for this user and not 6. This implies that the LDAP requests did not even get generated on the wire by the IDP server for the first 5 attempts. Interestingly the catalina,out file, with every supposed LDAP request, showed the following exception (Exception while attempting to search for a user store object) below:

<amLogEntry> 2011-05-25T15:16:51Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: http-10.22.156.88-8443-Processor20
Base context: OU=UNITED STATES,OU=North America,DC=novell,DC=com, Filter: (&(sAMAccountName=ncashell)(objectClass=User)), Scope: 2, Request Controls: null, UserId: go4f3881d9p6rx </amLogEntry>

<amLogEntry> 2011-05-25T15:16:51Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: http-10.22.156.88-8443-Processor20
Try connection: ldap://10.22.105.61 </amLogEntry>

<amLogEntry> 2011-05-25T15:16:51Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: http-10.22.156.88-8443-Processor20
Exception while attempting to search for a user store object! </amLogEntry> // problem

On the 6th attempt, we rePOST and it succeeds. What we see though is that the LDAP connections have been reset sometime after the above exception message. Only after these connections are reset will we see LDAP traffic on the wire

When it works, we see the following:

<amLogEntry> 2011-05-25T15:17:21Z DEBUG NIDS Application:
Method: LocalAuthenticationClass.authenticateWithPassword
Thread: http-10.22.156.88-8443-Processor20
Attempted authenticateWithPassword - id =ncashell  </amLogEntry>

<amLogEntry> 2011-05-25T15:17:21Z VERBOSE NIDS Application: Performing LDAP search (&(sAMAccountName=ncashell)(objectClass=User)) in context com.novell.nam.common.ldap.jndi.JNDIUserStoreSearchContext@22d5c7 </amLogEntry>

<amLogEntry> 2011-05-25T15:17:21Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: http-10.22.156.88-8443-Processor20
Base context: OU=UNITED STATES,OU=North America,DC=novell,DC=com, Filter: (&(sAMAccountName=ncashell)(objectClass=User)), Scope: 2, Request Controls: null, UserId: go4f3vjlf5r6x2 </amLogEntry>

<amLogEntry> 2011-05-25T15:17:21Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: http-10.22.156.88-8443-Processor20
Closing LDAP connection due to connection timeout! Interval: 66227, Timeout: 60000, Connection: Id: 84f2391b-96e1-40ef-b66e-218979eafb47, host: ldap://10.22.105.61 </amLogEntry>

<amLogEntry> 2011-05-25T15:17:21Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: http-10.22.156.88-8443-Processor20
Closing LDAP connection due to connection timeout! Interval: 66747, Timeout: 60000, Connection: Id: 57772232-2a3d-47d2-8872-bd61709fe640, host: ldap://10.22.105.61 </amLogEntry>