IDP server fails to come up despite host server being restarted

  • 7010020
  • 18-Jan-2012
  • 26-Apr-2012

Environment

Novell Access Manager 3.1 Linux Novell Identity Server
Novell Access Manager 3.1 Support Pack 3 applied

Situation

Access Manager 3.1 setup and working fine - users could access protected resources on the Linux Access Gateway (LAG) after having authenticated to the Identity (IDP) server. AFter making basic changes to the IDP server (Logging Statistics enabled), the Admin Console started to report that the IDP server was in a red state. Clicking on the status claimed that the IDP server had failed to start.

Users would get a blank page when accessing the IDP services as there was no responder listening.

Resolution

Delete the LDAP replica configuration and recreate it.

The key to troubleshooting these problems is to identify what service on the IDP server is not starting correctly. When the IDP server starts, it loads and initialises a number of independent configuration sets eg. the cluster configuration and the object in the configuration store containing the information. The IDP logs will start off with the following info

NIDPServletContext.doCommand(): Command set received! May wait for synchronization! Id: gxk476pt16g3, Command(s): start
Processing lifecycle command: start from set gxk476pt16g3 when state is: 0
NIDPContext.doInit(): Configuration:    <NIDPConfig enforceHTTPS="false" validateXML="false">
      <Cluster enabled="false"/>
      <ConsoleLog enabled="false"/>
      <Signing alias="signing" keyPassword="XX" keyStorePassword="XX" keystore="/opt/novell/devman/jcc/certs/idp/signing.keystore" type="jks"/>
      <Encrypting alias="encryption" keyPassword="XX" keyStorePassword="XX" keystore="/opt/novell/devman/jcc/certs/idp/encryption.keystore" type="jks
"/>
      <SSL alias="tomcat" keyPassword="XX" keyStorePassword="XX" keystore="/opt/novell/devman/jcc/certs/idp/connector.keystore" type="jks"/>
      <Trust keyPassword="XX" keyStorePassword="XX" keystore="/opt/novell/devman/jcc/certs/idp/truststore.keystore" type="jks"/>
      <OCSPTrust keyPassword="XX" keyStorePassword="XX" keystore="/opt/novell/devman/jcc/certs/idp/ocsp-truststore.keystore" type="jks"/>
      <LDAPAuthority>
         <LDAPCluster admin="ou=nidsUser,ou=UsersContainer,ou=Partition,ou=PartitionsContainer,ou=VCDN_Root,ou=accessManagerContainer,o=novell" confi
gDN="cn=SCCh9zn7g,cn=cluster,cn=nids,ou=accessManagerContainer,o=novell" password="XX" type="edir">
            <LDAPReplica displayName="Replica 1" host="ldaps://147.2.16.126" port="636" secure="true"/>
         </LDAPCluster>
      </LDAPAuthority>
   </NIDPConfig>

AFter this, the IDP logging configuration is initialised, followed by searches for

objectClass=nidsUserLookup // User lookup methods
objectClass=nidsSamlAttributeMap // Attribute maps for IDP configuration
objectClass=nidsImagePool // Images assigned to authentication cards
objectClass=nidsAuthentication // user stores
objectClass=nidsAuthClass // Authentication classes for that IDP cluster
objectClass=nidsAuthMethod // Authentication methods for that IDP cluster
objectClass=nidsLibertyTrustedSP // Liberty SPs
objectClass=nidsSaml1MeServiceProvider // SAML1 SPs
objectClass=nidsSaml1MeIdentityProvider // SAML1 IDPs
objectClass=nidsSaml2MeServiceProvider // SAML2 SPs
objectClass=nidsSaml2MeIdentityProvider // SAML2 IDPs

In the above case, we would see that the IDP server initialised fine up to the LDAP user stores but we stalled at this point:

<amLogEntry> 2012-01-18T08:04:35Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(2)-127.0.0.1
Base context: cn=SCC8xrfrm,cn=cluster,cn=nids,ou=accessManagerContainer,o=novell, Filter: (objectClass=nidsAuthentication), Scope: 2, Request Control
s: null, UserId: Startup </amLogEntry>

<amLogEntry> 2012-01-18T08:04:35Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(2)-127.0.0.1
Try connection: ldaps://10.8.2.59 </amLogEntry>

<amLogEntry> 2012-01-18T08:04:35Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(2)-127.0.0.1
Found 1 results! </amLogEntry>

<amLogEntry> 2012-01-18T08:04:36Z DEBUG NIDS Application:
Method: JNDIUtil.createUserStore
Thread: RMI TCP Connection(2)-127.0.0.1
actual max connections = 20 </amLogEntry>

<amLogEntry> 2012-01-18T08:04:36Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(2)-127.0.0.1
Initialized Connection Pool: Id: PL40310db1-426d-452a-b905-738b364a489d:23da9ccc-a9e7-46eb-893f-71daff51cdf3
    UserStore: Mercedes eDirectory
    Replica Host: ldaps://10.8.2.83
    Pool Open?: false
    Max Connections: 20
    User Name: cn=admin,o=mc </amLogEntry>

<amLogEntry> 2012-01-18T08:04:36Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(2)-127.0.0.1
Pool Id: PL40310db1-426d-452a-b905-738b364a489d:23da9ccc-a9e7-46eb-893f-71daff51cdf3, Opening pool on host: ldaps://10.8.2.83 </amLogEntry>

<amLogEntry> 2012-01-18T08:04:36Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(2)-127.0.0.1
Connection: 00d54d07-9940-4ef0-a59d-f225e408a908, Environment Parameters for InitialDirContext() method call:
Key: java.naming.factory.initial, Value: com.sun.jndi.ldap.LdapCtxFactory
Key: java.naming.provider.url, Value: ldaps://10.8.2.83:636
Key: com.sun.jndi.ldap.connect.timeout, Value: 0
Key: java.naming.security.principal, Value: cn=admin,o=mc
Key: java.naming.security.authentication, Value: simple
Key: java.naming.security.credentials, Value: *****
Key: java.naming.security.protocol, Value: ssl
Key: java.naming.ldap.factory.socket, Value: com.novell.nidp.common.util.net.client.NIDP_SSLSocketFactory
 </amLogEntry>

<amLogEntry> 2012-01-18T08:05:25Z DEBUG NIDS Application:
Method: NIDPServletContext.getHealth
Thread: RMI TCP Connection(5)-127.0.0.1
Starting NIDP Health Check! </amLogEntry>

// At no point did we get the "Open SUccessful!" message that indicates that the user store has successfully initialised as shown in the example below.

<amLogEntry> 2012-01-18T08:53:47Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(3)-127.0.0.1
Added property to DirContext Environment: Property Name: java.naming.ldap.attributes.binary, Value: GUID nDSPKITrustedRootCertificate </amLogEntry>

<amLogEntry> 2012-01-18T08:53:47Z DEBUG NIDS Application:
Method: JNDILogEventListener.accept
Thread: RMI TCP Connection(3)-127.0.0.1
Pool Id: PL80ab5fa2-1436-4fd2-b6fa-c2e976d0a16e:15c5a97b-f749-40a9-be6f-8fe6996322ac, Open Successful! </amLogEntry>

// Based on this information, we can identify the user store having the problem (only one in this setup and hence the IDP server failed to start). We removed and recreated the replica configuration and the IDP server started without issues.