Documentum – Java exception stack on iAPI/iDQL login

Recently, I was doing some sanity checks on a Documentum Server and I saw a Java exception stack while logging in using iAPI/iDQL to a Repository. It was reproducible for all Repositories. I’ve never seen something like that before (or at least I don’t remember it) so I was a little bit surprised. Whenever there are errors upon login, it is usually Documentum error messages that are printed and there is no exception stack. Since it took me some efforts finding the root cause, I thought about sharing it.

The exception stack displayed was the following one:

[dmadmin@cs-0 ~]$ echo "quit" | iapi gr_repo -Udmadmin -Pxxx

        EMC Documentum iapi - Interactive API interface
        (c) Copyright EMC Corp., 1992 - 2016
        All rights reserved.
        Client Library Release 7.3.0040.0025

Connecting to Server using docbase gr_repo
DfException:: THREAD: main; MSG: [DM_SESSION_I_SESSION_START]info:  "Session 0112d687800c9214 started for user dmadmin."; ERRORCODE: 100; NEXT: null
        at com.documentum.fc.client.impl.docbase.DocbaseExceptionMapper.newException(DocbaseExceptionMapper.java:57)
        at com.documentum.fc.client.impl.connection.docbase.MessageEntry.getException(MessageEntry.java:39)
        at com.documentum.fc.client.impl.connection.docbase.DocbaseMessageManager.getExceptionForAllMessages(DocbaseMessageManager.java:176)
        at com.documentum.fc.client.impl.connection.docbase.DocbaseConnection.getExceptionForAllMessages(DocbaseConnection.java:1518)
        at com.documentum.fc.client.impl.session.Session.getExceptionsForAllMessages(Session.java:1603)
        at com.documentum.fc.client.impl.session.SessionHandle.getExceptionsForAllMessages(SessionHandle.java:1301)
        at com.documentum.dmcl.impl.ApiContext.addMessages(ApiContext.java:423)
        at com.documentum.dmcl.impl.ApiContext.collectExceptionsForReporting(ApiContext.java:370)
        at com.documentum.dmcl.impl.GetMessageHandler.get(GetMessageHandler.java:23)
        at com.documentum.dmcl.impl.DmclApi.get(DmclApi.java:49)
        at com.documentum.dmcl.impl.DmclApiNativeAdapter.get(DmclApiNativeAdapter.java:145)
        at com.documentum.dmcl.impl.DmclApiNativeAdapter.get(DmclApiNativeAdapter.java:130)


Connected to Documentum Server running Release 7.3.0050.0039  Linux64.Oracle
Session id is s0
API> Bye
[dmadmin@cs-0 ~]$

The login was successful but still, a strange exception stack appeared. The first thing I did was checking the Repository log file but there was nothing out of the ordinary inside it except for one thing:

[dmadmin@cs-0 ~]$ cd $DOCUMENTUM/dba/log
[dmadmin@cs-0 log]$
[dmadmin@cs-0 log]$ grep -A3 "Agent Exec" gr_repo.log
Wed Sep 11 10:38:29 2019 [INFORMATION] [AGENTEXEC 1477] Detected during program initialization: Agent Exec connected to server gr_repo:  DfException:: THREAD: main; MSG: [DM_SESSION_I_SESSION_START]info:  "Session 0112d687800c8904 started for user dmadmin."; ERRORCODE: 100; NEXT: null
        at com.documentum.fc.client.impl.docbase.DocbaseExceptionMapper.newException(DocbaseExceptionMapper.java:57)
        at com.documentum.fc.client.impl.connection.docbase.MessageEntry.getException(MessageEntry.java:39)
        at com.documentum.fc.client.impl.connection.docbase.DocbaseMessageManager.getExceptionForAllMessages(DocbaseMessageManager.java:176)
        at com.documentu
[dmadmin@cs-0 log]$

While starting, the Agent Exec was therefore facing the same behavior with the exact same stack (which is cut at the 4th line but it’s the same stack until then so it’s safe to assume it’s the same). Therefore, to dig deeper and to find when the issue started exactly, I checked the logs from the agentexec/jobs since this will be kept until cleanup from the log purge and since it does login to the Repository:

[dmadmin@cs-0 log]$ cd $DOCUMENTUM/dba/log/gr_repo/agentexec
[dmadmin@cs-0 agentexec]$
[dmadmin@cs-0 agentexec]$ # Check the last file
[dmadmin@cs-0 agentexec]$ cat $(ls -tr job_* | tail -1)
Wed Sep 11 18:00:21 2019 [INFORMATION] [LAUNCHER 3184] Detected while preparing job dm_ConsistencyChecker for execution: Agent Exec connected to server gr_repo:  DfException:: THREAD: main; MSG: [DM_SESSION_I_SESSION_START]info:  "Session 0112d687800c8974 started for user dmadmin."; ERRORCODE: 100; NEXT: null
        at com.documentum.fc.client.impl.docbase.DocbaseExceptionMapper.newException(DocbaseExceptionMapper.java:57)
        at com.documentum.fc.client.impl.connection.docbase.MessageEntry.getException(MessageEntry.java:39)
        at com.documentum.fc.client.impl.connection.docbase.DocbaseMessageManager.getExceptionForAllMessages(DocbaseMessageManager.java:176)
        at com.documentu
[dmadmin@cs-0 agentexec]$
[dmadmin@cs-0 agentexec]$ # Finding the first file with the error
[dmadmin@cs-0 agentexec]$ for f in $(ls -tr); do r=$(grep "_I_SESSION_START.*ERRORCODE" "${f}"); if [[ "${r}" != "" ]]; then echo "${r}"; break; fi; done
Tue Sep 10 18:00:06 2019 [INFORMATION] [LAUNCHER 31113] Detected while preparing job dm_ConsistencyChecker for execution: Agent Exec connected to server gr_repo:  DfException:: THREAD: main; MSG: [DM_SESSION_I_SESSION_START]info:  "Session 0112d687800c8827 started for user dmadmin."; ERRORCODE: 100; NEXT: null
[dmadmin@cs-0 agentexec]$

In all the job’s sessions files, there were the same stack (or rather a piece of the stack). At first, I didn’t understand where this was coming from, all I know was that it was linked somehow to the login inside the Repository and that it appeared for the first time on the date returned by my last command above. It was not really an error message since it wasn’t showing any “_E_” messages but it was still printing an exception.

Knowing when it appeared the first time, I looked at all the files that have been modified on that day and among log files, which are expected and can be ignored, there were the dfc.properties file. This provided me the reason for this message: it was actually due to enabling the diagnostic mode on the dfc.properties of the Documentum Server. To be exact, it was due to the “dfc.diagnostics.exception.include_stack=true” entry:

[dmadmin@cs-0 agentexec]$ tail -5 $DOCUMENTUM_SHARED/config/dfc.properties
dfc.session.secure_connect_default=secure
dfc.time_zone=UTC
dfc.diagnostics.resources.enable=true
dfc.diagnostics.exception.include_stack=true
dfc.tracing.print_exception_stack=true
[dmadmin@cs-0 agentexec]$
[dmadmin@cs-0 agentexec]$ echo "quit" | iapi gr_repo -Udmadmin -Pxxx

        EMC Documentum iapi - Interactive API interface
        (c) Copyright EMC Corp., 1992 - 2016
        All rights reserved.
        Client Library Release 7.3.0040.0025

Connecting to Server using docbase gr_repo
DfException:: THREAD: main; MSG: [DM_SESSION_I_SESSION_START]info:  "Session 0112d687800c9235 started for user dmadmin."; ERRORCODE: 100; NEXT: null
        at com.documentum.fc.client.impl.docbase.DocbaseExceptionMapper.newException(DocbaseExceptionMapper.java:57)
        at com.documentum.fc.client.impl.connection.docbase.MessageEntry.getException(MessageEntry.java:39)
        at com.documentum.fc.client.impl.connection.docbase.DocbaseMessageManager.getExceptionForAllMessages(DocbaseMessageManager.java:176)
        at com.documentum.fc.client.impl.connection.docbase.DocbaseConnection.getExceptionForAllMessages(DocbaseConnection.java:1518)
        at com.documentum.fc.client.impl.session.Session.getExceptionsForAllMessages(Session.java:1603)
        at com.documentum.fc.client.impl.session.SessionHandle.getExceptionsForAllMessages(SessionHandle.java:1301)
        at com.documentum.dmcl.impl.ApiContext.addMessages(ApiContext.java:423)
        at com.documentum.dmcl.impl.ApiContext.collectExceptionsForReporting(ApiContext.java:370)
        at com.documentum.dmcl.impl.GetMessageHandler.get(GetMessageHandler.java:23)
        at com.documentum.dmcl.impl.DmclApi.get(DmclApi.java:49)
        at com.documentum.dmcl.impl.DmclApiNativeAdapter.get(DmclApiNativeAdapter.java:145)
        at com.documentum.dmcl.impl.DmclApiNativeAdapter.get(DmclApiNativeAdapter.java:130)


Connected to Documentum Server running Release 7.3.0050.0039  Linux64.Oracle
Session id is s0
API> Bye
[dmadmin@cs-0 agentexec]$
[dmadmin@cs-0 agentexec]$ sed -i sed 's,^dfc.diagnostics.exception.include_stack,#&,' $DOCUMENTUM_SHARED/config/dfc.properties
[dmadmin@cs-0 agentexec]$
[dmadmin@cs-0 agentexec]$ echo "quit" | iapi gr_repo -Udmadmin -Pxxx

        EMC Documentum iapi - Interactive API interface
        (c) Copyright EMC Corp., 1992 - 2016
        All rights reserved.
        Client Library Release 7.3.0040.0025

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

Connected to Documentum Server running Release 7.3.0050.0039  Linux64.Oracle
Session id is s0
API> Bye
[dmadmin@cs-0 agentexec]$

As you can see above, commenting the line “dfc.diagnostics.exception.include_stack=true” (meaning setting it to false, the default value) caused the exception stack to disappear. Since I was curious about this stack and wanted confirmation that this is “expected”, I opened a case with the OpenText Support (#4331438) and they confirmed me after a few days that it wasn’t considered an “ERROR“, it was more of an “INFO” message. It’s a strange way to display informative messages but hey, who am I to judge!