In a previous blog, I talked about the automation of the LDAP/LDAPs creation. However, the first time that I applied these steps, I actually faced an issue and I couldn’t really get my head around it, at first. This will be a rather short post but I still wanted to share my thoughts because it might avoid you some headache. The issue is only linked to the SSL part of the setup so there is no problem with the basis non-secure LDAP communications.

So, after applying all the steps, everything went fine and I therefore tried to run the dm_LDAPSynchronization job to validate the setup. Doing so, the generated log file wasn’t so great:

[dmadmin@content-server-0 ~]$ cat $DOCUMENTUM/dba/log/repo01/sysadmin/LDAPSynchronizationDoc.txt
LDAPSynchronization Report For DocBase repo01 As Of 2019/09/22 12:45:57

2019-09-22 12:45:56:124 UTC [default task-79]: LDAP Synchronization Started @ Sun Sep 22 12:45:56 UTC 2019
2019-09-22 12:45:56:124 UTC [default task-79]:
2019-09-22 12:45:56:124 UTC [default task-79]: $JMS_HOME/server/DctmServer_MethodServer/deployments/ServerApps.ear/lib/dmldap.jar
2019-09-22 12:45:56:125 UTC [default task-79]: ---------------------------------------------------------------------------------
2019-09-22 12:45:56:125 UTC [default task-79]: Product-Name : Content Server-LDAPSync
2019-09-22 12:45:56:125 UTC [default task-79]: Product-Version : 16.4.0110.0167
2019-09-22 12:45:56:125 UTC [default task-79]: Implementation-Version : 16.4.0110.0167
2019-09-22 12:45:56:125 UTC [default task-79]: ---------------------------------------------------------------------------------
2019-09-22 12:45:56:125 UTC [default task-79]:
2019-09-22 12:45:56:126 UTC [default task-79]: Preparing LDAP Synchronization...
2019-09-22 12:45:57:101 UTC [default task-79]: INFO: Job Status: [LDAP Synchronization Started @ Sun Sep 22 12:45:56 UTC 2019]
2019-09-22 12:45:57:120 UTC [default task-79]: INFO: Job Status updated
2019-09-22 12:45:58:415 UTC [default task-79]: INFO: List of Ldap Configs chosen for Synchronization
2019-09-22 12:45:58:415 UTC [default task-79]: INFO:    >>>0812d6878000252c - Internal_LDAP<<<
2019-09-22 12:45:58:415 UTC [default task-79]: INFO:
2019-09-22 12:45:58:418 UTC [default task-79]:
2019-09-22 12:45:58:418 UTC [default task-79]: ==================================================================================
2019-09-22 12:45:58:420 UTC [default task-79]: Starting Sychronization for ldap config object >>>Internal_LDAP<<< ...
2019-09-22 12:45:58:425 UTC [default task-79]: Unexpected Error. Caused by: [DM_LDAP_SYNC_E_EXCEPTION_ERROR]error:  "Ldap Config Property "certdb_location" has invalid value "ldap_chain"."
2019-09-22 12:45:58:426 UTC [default task-79]: ERROR: DmLdapException:: THREAD: default task-79; MSG: [DM_LDAP_SYNC_E_EXCEPTION_ERROR]error:  "Ldap Config Property "certdb_location" has invalid value "ldap_chain"."; ERRORCODE: 100; NEXT: null
        at com.documentum.ldap.internal.sync.SynchronizationContextBuilder.getCertDbLocation(SynchronizationContextBuilder.java:859)
        at com.documentum.ldap.internal.sync.SynchronizationContextBuilder.setCertDbLocation(SynchronizationContextBuilder.java:225)
        at com.documentum.ldap.internal.sync.SynchronizationContextBuilder.buildSynchronizationContext(SynchronizationContextBuilder.java:49)
        at com.documentum.ldap.LDAPSync.prepareSync(LDAPSync.java:438)
        at com.documentum.ldap.LDAPSync.processJob(LDAPSync.java:238)
        at com.documentum.ldap.LDAPSync.execute(LDAPSync.java:80)
        at com.documentum.mthdservlet.DfMethodRunner.runIt(Unknown Source)
        at com.documentum.mthdservlet.AMethodRunner.runAndReturnStatus(Unknown Source)
        at com.documentum.mthdservlet.DoMethod.invokeMethod(Unknown Source)
        at com.documentum.mthdservlet.DoMethod.doPost(Unknown Source)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:86)
        at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
        at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
        at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
        at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
        at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
        at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58)
        at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:72)
        at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
        at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:282)
        at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:261)
        at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:80)
        at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:172)
        at io.undertow.server.Connectors.executeRootHandler(Connectors.java:199)
        at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:774)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

2019-09-22 12:45:58:426 UTC [default task-79]: WARNING:   **** Skipping Ldap Config Object - Internal_LDAP ****
2019-09-22 12:45:58:775 UTC [default task-79]: Synchronization of ldap config object >>>Internal_LDAP<<< is finished
2019-09-22 12:45:58:775 UTC [default task-79]: ==================================================================================
2019-09-22 12:45:58:775 UTC [default task-79]:
2019-09-22 12:45:58:786 UTC [default task-79]: INFO: Job Status: [dm_LDAPSynchronization Tool had ERRORS at 2019/09/22 12:45:58. Total duration was 2 seconds.View the job's report for details.]
2019-09-22 12:45:58:800 UTC [default task-79]: INFO: Job Status updated
2019-09-22 12:45:58:800 UTC [default task-79]: LDAP Synchronization Ended @ Sun Sep 22 12:45:58 UTC 2019
2019-09-22 12:45:58:800 UTC [default task-79]: Session s2 released successfully
Report End  2019/09/22 12:45:58
[dmadmin@content-server-0 ~]$

 

After a bunch of checks inside the repository, everything seemed fine. All the objects had the correct content, the correct references, aso… However there was one thing that wasn’t exactly as per the KB6321243 and that was the extension of the Trust Chain file. If you look at the basis of SSL Certificate encodings, then there are two main possibilities: DER (binary = not readable) or PEM (ASCII = readable). In addition to that, you can also have files with CRT or CER extensions but they are always either DER or PEM encoded. The KB asks you to have a PEM encoded SSL Certificate so this file can technically have either a “.pem” or “.cer” or “.crt” extension, that’s almost synonymous. Therefore, here I was, thinking that I could keep my “.crt” extension for the PEM encoded SSL Trust Chain.

To validate that this was the issue, I switched my file to the “.pem” extension and updated the “dm_location” Object:

[dmadmin@content-server-0 ~]$ cd $DOCUMENTUM/dba/secure/ldapdb
[dmadmin@content-server-0 ldapdb]$ mv ldap_chain.crt ldap_chain.pem
[dmadmin@content-server-0 ldapdb]$ 
[dmadmin@content-server-0 ldapdb]$ iapi repo01 -U${USER} -Pxxx


        OpenText Documentum iapi - Interactive API interface
        Copyright (c) 2018. OpenText Corporation
        All rights reserved.
        Client Library Release 16.4.0110.0058

Connecting to Server using docbase repo01
[DM_SESSION_I_SESSION_START]info:  "Session 0112d68780001402 started for user dmadmin."

Connected to OpenText Documentum Server running Release 16.4.0110.0167  Linux64.Oracle
Session id is s0
API> retrieve,c,dm_location where object_name='ldap_chain'
...
3a12d68780002522
API> get,c,l,file_system_path
...
$DOCUMENTUM/dba/secure/ldapdb/ldap_chain.cer
API> set,c,l,file_system_path
SET> $DOCUMENTUM/dba/secure/ldapdb/ldap_chain.pem
...
OK
API> get,c,l,file_system_path
...
$DOCUMENTUM/dba/secure/ldapdb/ldap_chain.pem
API> save,c,l
...
OK
API> ?,c,UPDATE dm_job OBJECTS set run_now=true, set a_next_invocation=DATE(NOW) WHERE object_name='dm_LDAPSynchronization'
objects_updated
---------------
              1
(1 row affected)
[DM_QUERY_I_NUM_UPDATE]info:  "1 objects were affected by your UPDATE statement."

API> exit
Bye
[dmadmin@content-server-0 ldapdb]$

 

With the above, I just changed the extension of the file on the file system and its reference in the “dm_location” Object. The last iAPI command triggered the dm_LDAPSynchronization job to run. Checking the new log file, the issue was indeed solved which confirmed that despite the fact that the Trust Chain was a PEM encoded certificate, it wasn’t enough. There is actually a hardcoded value/check inside Documentum, which forces you to use the “.pem” extension and nothing else:

[dmadmin@content-server-0 ldapdb]$ cat $DOCUMENTUM/dba/log/repo01/sysadmin/LDAPSynchronizationDoc.txt
LDAPSynchronization Report For DocBase repo01 As Of 2019/09/22 13:19:33

2019-09-22 13:19:30:360 UTC [default task-87]: LDAP Synchronization Started @ Sun Sep 22 13:19:30 UTC 2019
2019-09-22 13:19:30:360 UTC [default task-87]:
2019-09-22 13:19:30:361 UTC [default task-87]: $JMS_HOME/server/DctmServer_MethodServer/deployments/ServerApps.ear/lib/dmldap.jar
2019-09-22 13:19:30:367 UTC [default task-87]: ---------------------------------------------------------------------------------
2019-09-22 13:19:30:367 UTC [default task-87]: Product-Name : Content Server-LDAPSync
2019-09-22 13:19:30:367 UTC [default task-87]: Product-Version : 16.4.0110.0167
2019-09-22 13:19:30:367 UTC [default task-87]: Implementation-Version : 16.4.0110.0167
2019-09-22 13:19:30:367 UTC [default task-87]: ---------------------------------------------------------------------------------
2019-09-22 13:19:30:367 UTC [default task-87]:
2019-09-22 13:19:30:370 UTC [default task-87]: Preparing LDAP Synchronization...
2019-09-22 13:19:32:425 UTC [default task-87]: INFO: Job Status: [LDAP Synchronization Started @ Sun Sep 22 13:19:30 UTC 2019]
2019-09-22 13:19:32:453 UTC [default task-87]: INFO: Job Status updated
2019-09-22 13:19:34:292 UTC [default task-87]: INFO: List of Ldap Configs chosen for Synchronization
2019-09-22 13:19:34:292 UTC [default task-87]: INFO:    >>>0812d6878000252c - Internal_LDAP<<<
2019-09-22 13:19:34:292 UTC [default task-87]: INFO:
2019-09-22 13:19:34:294 UTC [default task-87]:
2019-09-22 13:19:34:294 UTC [default task-87]: ==================================================================================
2019-09-22 13:19:34:297 UTC [default task-87]: Starting Sychronization for ldap config object >>>Internal_LDAP<<< ...
2019-09-22 13:19:35:512 UTC [default task-87]: INFO: Directory Type: Sun ONE Directory Server ...
2019-09-22 13:19:35:517 UTC [default task-87]: INFO: Ldap Connection: SSL connection
2019-09-22 13:19:35:517 UTC [default task-87]: INFO: ldap://ldap.domain.com:636
2019-09-22 13:19:35:517 UTC [default task-87]: INFO: {java.naming.provider.url=ldap://ldap.domain.com:636, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
2019-09-22 13:19:35:597 UTC [Thread-91752]: INFO: DM_LDAP_IGNORE_HOSTNAME_CHECK environment variable is enabled.
2019-09-22 13:19:35:598 UTC [Thread-91752]: INFO: Skipping hostname check
2019-09-22 13:19:35:598 UTC [Thread-91752]: INFO: DctmTrustMangaer.checkServerTrusted(): Successfully validated the certificate chain sent from server.
2019-09-22 13:19:35:635 UTC [default task-87]: INFO: DM_LDAP_IGNORE_HOSTNAME_CHECK environment variable is enabled.
2019-09-22 13:19:35:635 UTC [default task-87]: INFO: Skipping hostname check
2019-09-22 13:19:35:635 UTC [default task-87]: INFO: DctmTrustMangaer.checkServerTrusted(): Successfully validated the certificate chain sent from server.
2019-09-22 13:19:35:663 UTC [default task-87]: INFO: LDAP Search Retry: is_child_context = true
2019-09-22 13:19:35:663 UTC [default task-87]: INFO: LDAP Search Retry: Retry count = 1
2019-09-22 13:19:35:665 UTC [default task-87]: Starting the group synchronization...
...
2019-09-22 13:19:35:683 UTC [default task-87]: Group synchronization finished.
2019-09-22 13:19:35:683 UTC [default task-87]:
2019-09-22 13:19:35:683 UTC [default task-87]: INFO: Updating Last Run Time: [20190922131935Z]
2019-09-22 13:19:35:683 UTC [default task-87]: INFO: Updating Last Change No: [null]
2019-09-22 13:19:35:749 UTC [default task-87]: INFO: Ldap Config Object >>>>Internal_LDAP<<<< updated
2019-09-22 13:19:35:751 UTC [default task-87]: Disconnected from LDAP Server successfully.
2019-09-22 13:19:36:250 UTC [default task-87]: Synchronization of ldap config object >>>Internal_LDAP<<< is finished
2019-09-22 13:19:36:250 UTC [default task-87]: ==================================================================================
2019-09-22 13:19:36:250 UTC [default task-87]:
2019-09-22 13:19:36:265 UTC [default task-87]: INFO: Job Status: [dm_LDAPSynchronization Tool Completed with WARNINGS at 2019/09/22 13:19:36. Total duration was 6 seconds.]
2019-09-22 13:19:36:278 UTC [default task-87]: INFO: Job Status updated
2019-09-22 13:19:36:278 UTC [default task-87]: LDAP Synchronization Ended @ Sun Sep 22 13:19:36 UTC 2019
2019-09-22 13:19:36:278 UTC [default task-87]: Session s2 released successfully
Report End  2019/09/22 13:19:36
[dmadmin@content-server-0 ldapdb]$

 

A pretty annoying design but there is nothing you can do about it. Fortunately, it’s not hard to fix the issue once you know what’s the problem!