Infrastructure at your Service

David Diab

Documentum : Dctm job locked after docbase installation

A correct configuration of Documentum jobs is paramount, that’s why it is the first thing we do after the docbase installation.
A few days ago, I configured the jobs on a new docbase using DQL, and I got an error because a job is locked by the user dmadmin.

The error message was:

DQL> UPDATE dm_job OBJECTS SET target_server=' ' WHERE target_server!=' ' ;
...
[DM_QUERY_F_UP_SAVE]fatal:  "UPDATE:  An error has occurred during a save operation."

[DM_SYSOBJECT_E_LOCKED]error:  "The operation on dm_FTQBS_WEEKLY sysobject was unsuccessful because it is locked by user dmadmin."

I checked the status of this job:

API> ?,c,select r_object_id from dm_job where object_name ='dm_FTQBS_WEEKLY';
r_object_id
----------------
0812D68780000ca6
(1 row affected)

API> dump,c,0812D68780000ca6
...
USER ATTRIBUTES

  object_name                     : dm_FTQBS_WEEKLY
  title                           :
  subject                         : qbs weekly job
...
  start_date                      : 2/28/2019 05:21:15
  expiration_date                 : 2/28/2027 23:00:00
...
  is_inactive                     : T
  inactivate_after_failure        : F
...
  run_now                         : T
...

SYSTEM ATTRIBUTES

  r_object_type                   : dm_job
  r_creation_date                 : 2/28/2019 05:21:15
  r_modify_date                   : 2/28/2019 05:24:48
  r_modifier                      : dmadmin
...
  r_lock_owner                    : dmadmin
  r_lock_date                     : 2/28/2019 05:24:48
...

APPLICATION ATTRIBUTES

...
  a_status                        :
  a_is_hidden                     : F
...
  a_next_invocation               : 3/7/2019 05:21:15

INTERNAL ATTRIBUTES

  i_is_deleted                    : F
...

The job was locked 3 minutes after the creation date… And still locked since (4 days).

Let’s check job logs:

[dmadmin@CONTENT_SERVER1 ~]$ ls -rtl $DOCUMENTUM/dba/log/repository1/agentexec/*0812D68780000ca6*
-rw-r--r--. 1 dmadmin dmadmin   0 Feb 28 05:24 /app/dctm/server/dba/log/repository1/agentexec/job_0812D68780000ca6.lck
-rw-rw-rw-. 1 dmadmin dmadmin 695 Feb 28 05:24 /app/dctm/server/dba/log/repository1/agentexec/job_0812D68780000ca6
[dmadmin@CONTENT_SERVER1 ~]$
[dmadmin@CONTENT_SERVER1 ~]$ cat /app/dctm/server/dba/log/repository1/agentexec/job_0812D68780000ca6
Thu Feb 28 05:24:50 2019 [ERROR] [LAUNCHER 20749] Detected while preparing job ? for execution: Command Failed: connect,repository1.repository1,dmadmin,'',,,try_native_first, 
status: 0, with error message [DM_DOCBROKER_E_NO_SERVERS_FOR_DOCBASE]error:  "The DocBroker running on host (CONTENT_SERVER1:1489) does not know of a server for the specified docbase (repository1)"
...NO HEADER (RECURSION) No session id for current job.
Thu Feb 28 05:24:50 2019 [FATAL ERROR] [LAUNCHER 20749] Detected while preparing job ? for execution: Command Failed: connect,repository1.repository1,dmadmin,'',,,try_native_first, status: 0, with error message .
..NO HEADER (RECURSION) No session id for current job.

I noted three important information here:
1. The DocBroker consider that the docbase is stopped when the AgentExec sent the request.
2. The timestamp corresponds to the installation date of the docbase.
3. LAUNCHER 20749.

I checked the install logs to confirm the first point:

[dmadmin@CONTENT_SERVER1 ~]$ egrep " The installer will s.*. repository1" $DOCUMENTUM/product/7.3/install/logs/install.log*
/app/dctm/server/product/7.3/install/logs/install.log.2019.2.28.8.7.22:05:03:24,757  INFO [main]  - The installer will start component process for repository1.
/app/dctm/server/product/7.3/install/logs/install.log.2019.2.28.8.7.22:05:24:39,588  INFO [main]  - The installer will stop component process for repository1.
/app/dctm/server/product/7.3/install/logs/install.log.2019.2.28.8.7.22:05:26:49,110  INFO [main]  - The installer will start component process for repository1.

The AgentExec logs:

[dmadmin@CONTENT_SERVER1 ~]$ ls -rtl $DOCUMENTUM/dba/log/repository1/agentexec/*agentexec.log*
-rw-rw-rw-. 1 dmadmin dmadmin    640 Feb 28 05:24 agentexec.log.save.02.28.19.05.27.54
-rw-rw-rw-. 1 dmadmin dmadmin    384 Feb 28 05:36 agentexec.log.save.02.28.19.05.42.26
-rw-r-----. 1 dmadmin dmadmin      0 Feb 28 05:42 agentexec.log.save.02.28.19.09.51.24
...
-rw-r-----. 1 dmadmin dmadmin 569463 Mar  8 09:11 agentexec.log
[dmadmin@CONTENT_SERVER1 ~]$
[dmadmin@CONTENT_SERVER1 ~]$ cat $DOCUMENTUM/dba/log/repository1/agentexec/agentexec.log.save.02.28.19.05.27.54
Thu Feb 28 05:17:48 2019 [INFORMATION] [LAUNCHER 19584] Detected during program initialization: Version: 7.3.0050.0039  Linux64
Thu Feb 28 05:22:19 2019 [INFORMATION] [LAUNCHER 20191] Detected during program initialization: Version: 7.3.0050.0039  Linux64
Thu Feb 28 05:22:49 2019 [INFORMATION] [LAUNCHER 20253] Detected during program initialization: Version: 7.3.0050.0039  Linux64
Thu Feb 28 05:24:19 2019 [INFORMATION] [LAUNCHER 20555] Detected during program initialization: Version: 7.3.0050.0039  Linux64
Thu Feb 28 05:24:49 2019 [INFORMATION] [LAUNCHER 20749] Detected during program initialization: Version: 7.3.0050.0039  Linux64

I found here the LAUNCHER 20749 noted above ;) So, this job corresponds to the last job executed by the AgentExec before being stopped.
The AgentExec was up, the Docbase should be up also, but the DocBroker said that the docbase is down :(

Now, the question is : when execatly the DocBroker was informed that the docbase is shut down?

[dmadmin@CONTENT_SERVER1 ~]$ cat $DOCUMENTUM/dba/log/repository1.log.save.02.28.2019.05.26.49
...
2019-02-28T05:24:48.644873      20744[20744]    0112D68780000003        [DM_DOCBROKER_I_PROJECTING]info:  "Sending information to Docbroker located on host (CONTENT_SERVER1) with port (1489).  
Information: (Config(repository1), Proximity(1), Status(Server shut down by user (dmadmin)), Dormancy Status(Active))."

To recapitulate:
– 05:24:48.644873 : Docbase shut down and DocBroker informed
– 05:24:49 : AgentExec sent request to DocBroker

So, we can say that the AgentExec was still alive after the docbase stop!

Now, to resolve the issue it is easy :D

API> unlock,c,0812D68780000ca6
...
OK

I didn’t find in the logs when exactly the docbase stop the AgentExec, I guess the docbase request the stop (kill) but don’t check if it has been really stopped.
I confess that I encounter this error many times after docbase installation, that’s why it is useful to know why and how to resolve it quickly. I advise you to configure Dctm jobs after each installation, at least check if the r_lock_date is set and if it is justified.

David Diab
David Diab