Some time ago, I was working on the preparation of an upgrade of a Content Server and everything was working fine so I was about to begin but just before that I checked our monitoring interface for this environment to crosscheck and I saw the following alerts coming from the log file of the docbases installed on this CS:

2016-04-05T10:47:01.411651      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"

 

As you might know, an object with an ID starting with “3c” represents the dm_docbase_config and therefore I was a little bit afraid when I saw this alert. So first thing, I tried to open an idql session to see if the docbase was responding:

[dmadmin@content_server_01 log]$ iapi DOCBASE1 -Udmadmin -Pxxx


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


Connecting to Server using docbase DOCBASE1
[DM_SESSION_I_SESSION_START]info:  "Session 013f245a800d7441 started for user dmadmin."


Connected to Documentum Server running Release 7.2.0050.0214  Linux64.Oracle
Session id is s0
API> retrieve,c,dm_docbase_config
...
3c3f245a60000210
API> exit
Bye

 

Ok so apparently the docbase is working properly, we can access D2, DA, the idql is also working and even the dm_docbase_config object can be retrieved and seen but there is still the exact same error in the log file coming every 5 minutes exactly. So I took a look at the error message in detail because I didn’t want to scroll hundreds of lines for maybe nothing. The string description containing the object ID wouldn’t really be useful inside the log file to find what might be the root cause and the same thing apply for the DM_OBJ_MGR_E_FETCH_FAIL error, it would just print the exact same error again and again with just different timestamps. When thinking about that in my mind, I actually realised that the 2 or 3 error lines I was able to see on my screen were completely exact – except the timestamps – and that include the process ID that is throwing this error (second column on the log file).

 

With this new information, I tried to find all log entries related to this process ID:

[dmadmin@content_server_01 log]$ grep "21425[21425]" $DOCUMENTUM/dba/log/DOCBASE1.log | more
2016-04-04T06:58:09.315163      21425[21425]    0000000000000000        [DM_SERVER_I_START_SERVER]info:  "Docbase DOCBASE1 attempting to open"
2016-04-04T06:58:09.315282      21425[21425]    0000000000000000        [DM_SERVER_I_START_KEY_STORAGE_MODE]info:  "Docbase DOCBASE1 is using database for cryptographic key storage"
2016-04-04T06:58:09.315316      21425[21425]    0000000000000000        [DM_SERVER_I_START_SERVER]info:  "Docbase DOCBASE1 process identity: user(dmadmin)"
2016-04-04T06:58:11.400017      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Post Upgrade Processing."
2016-04-04T06:58:11.401753      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Base Types."
2016-04-04T06:58:11.404252      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmRecovery."
2016-04-04T06:58:11.412344      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmACL."
2016-04-04T06:58:11.438249      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDocbaseIdMap."
2016-04-04T06:58:11.447435      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Error log streams."
2016-04-04T06:58:11.447915      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmUser."
2016-04-04T06:58:11.464912      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmGroup."
2016-04-04T06:58:11.480200      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmSysObject."
2016-04-04T06:58:11.515201      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmExprCode."
2016-04-04T06:58:11.524604      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmKey."
2016-04-04T06:58:11.533883      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmValueAssist."
2016-04-04T06:58:11.541708      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmValueList."
2016-04-04T06:58:11.551492      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmValueQuery."
2016-04-04T06:58:11.559569      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmValueFunc."
2016-04-04T06:58:11.565830      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmExpression."
2016-04-04T06:58:11.594764      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmLiteralExpr."
2016-04-04T06:58:11.603279      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmBuiltinExpr."
2016-04-04T06:58:11.625736      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmFuncExpr."
2016-04-04T06:58:11.636930      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmCondExpr."
2016-04-04T06:58:11.663622      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmCondIDExpr."
2016-04-04T06:58:11.707363      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDDInfo."
2016-04-04T06:58:11.766883      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmScopeConfig."
2016-04-04T06:58:11.843335      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDisplayConfig."
2016-04-04T06:58:11.854414      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmNLSDDInfo."
2016-04-04T06:58:11.878566      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDomain."
2016-04-04T06:58:11.903844      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmAggrDomain."
2016-04-04T06:58:11.929480      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmMountPoint."
2016-04-04T06:58:11.957705      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmLocation."
2016-04-04T06:58:12.020403      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Server Configuration."
2016-04-04T06:58:12.135418      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmPolicy."
2016-04-04T06:58:12.166923      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDDCommonInfo."
2016-04-04T06:58:12.196057      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDDAttrInfo."
2016-04-04T06:58:12.238040      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDDTypeInfo."
2016-04-04T06:58:12.269202      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmRelation."
2016-04-04T06:58:12.354573      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmForeignKey."
2016-04-04T06:58:12.387309      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmEvent."
2016-04-04T06:58:12.403895      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize DQL."
2016-04-04T06:58:12.405622      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmFolder."
2016-04-04T06:58:12.433583      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmDocument."
2016-04-04T06:58:12.480234      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Plugin Type."
2016-04-04T06:58:12.490196      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmNote."
2016-04-04T06:58:12.518305      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmComposite."
2016-04-04T06:58:12.529351      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmStorage."
2016-04-04T06:58:12.539944      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Common area."
2016-04-04T06:58:12.612097      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize File Store."
2016-04-04T06:58:12.675604      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Optical Store."
2016-04-04T06:58:12.717573      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Linked Stores."
2016-04-04T06:58:12.803227      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Distributed Stores."
2016-04-04T06:58:13.102632      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Blob Stores."
2016-04-04T06:58:13.170074      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize External Store."
2016-04-04T06:58:13.242012      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize External File Store."
2016-04-04T06:58:13.305767      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize External URL."
2016-04-04T06:58:13.363407      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize External Free."
2016-04-04T06:58:13.429547      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmContent."
2016-04-04T06:58:13.461400      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmiSubContent."
2016-04-04T06:58:13.508588      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmOutputDevice."
2016-04-04T06:58:13.630872      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmMethod."
2016-04-04T06:58:13.689265      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmRouter."
2016-04-04T06:58:13.733289      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmFederation."
2016-04-04T06:58:13.807554      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmAliasSet."
2016-04-04T06:58:13.871634      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Content Addressable Storage."
2016-04-04T06:58:13.924874      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Formats."
2016-04-04T06:58:13.995154      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Convert."
2016-04-04T06:58:13.998050      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Indices."
2016-04-04T06:58:14.025587      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Dump Files."
2016-04-04T06:58:14.107689      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Load Files."
2016-04-04T06:58:14.176232      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize In Box."
2016-04-04T06:58:14.225954      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Distributed References."
2016-04-04T06:58:14.292782      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Client Registrations."
2016-04-04T06:58:14.319699      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Client Rights."
2016-04-04T06:58:14.330420      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Client Rights Domain."
2016-04-04T06:58:14.356866      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Business Activities."
2016-04-04T06:58:14.411545      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Business Processes."
2016-04-04T06:58:14.444264      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Packages."
2016-04-04T06:58:14.493478      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Workitems."
2016-04-04T06:58:14.521836      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Workflows."
2016-04-04T06:58:14.559605      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Audit Trail."
2016-04-04T06:58:14.639303      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Clean Old Links."
2016-04-04T06:58:14.640511      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Compute Internal Type Tag Cache."
2016-04-04T06:58:14.696040      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize LastActionProcs."
2016-04-04T06:58:14.696473      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize User Types."
2016-04-04T06:58:14.696828      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Start Up - Phase 1."
2016-04-04T06:58:15.186812      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Start Up - Phase 2."
2016-04-04T06:58:15.666149      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Crypto Objects."
2016-04-04T06:58:15.677119      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Queue Views."
2016-04-04T06:58:15.678343      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Port Info Views."
2016-04-04T06:58:15.679532      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Global Cache Finalization."
2016-04-04T06:58:16.939100      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize National Language Character Translation."
2016-04-04T06:58:16.941815      21425[21425]    0000000000000000        [DM_CHARTRANS_I_TRANSLATOR_OPENED]info:  "Translator in directory ($DOCUMENTUM/product/7.2/install/external_apps/nls_chartrans) was added succesfully initialized.  Translator specifics: (Chararacter Translator: , Client Locale: (Windows :(4099), Version: 4.0), CharSet: ISO_8859-1, Language: English_US, UTC Offset: 0, Date Format:%2.2d/%2.2d/%2.2d %2.2d:%2.2d:%2.2d, Java Locale:en, Server Locale: (Linux :(8201), Version: 2.4), CharSet: UTF-8, Language: English_US, UTC Offset: 0, Date Format:%2.2d/%2.2d/%2.2d %2.2d:%2.2d:%2.2d, Java Locale:en, Shared Library: $DOCUMENTUM/product/7.2/install/external_apps/nls_chartrans/unitrans.so)"
2016-04-04T06:58:16.942377      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize LDAP setup."
2016-04-04T06:58:16.961767      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Distributed change-checking."
2016-04-04T06:58:17.022448      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Fulltext Plugin and Configuration."
2016-04-04T06:58:17.113147      21425[21425]    0000000000000000        [DM_FULLTEXT_T_QUERY_PLUGIN_VERSION]info:  "Loaded FT Query Plugin: $DOCUMENTUM/product/7.2/bin/libDsearchQueryPlugin.so, API Interface version: 1.0, Build number: HEAD; Sep 14 2015 07:48:06, FT Engine version: xPlore version 1.5.0020.0048"
2016-04-04T06:58:17.122313      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Distributed Content."
2016-04-04T06:58:17.125027      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Distributed Content Map."
2016-04-04T06:58:17.125467      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Distributed Content Digital Signatures."
2016-04-04T06:58:17.621156      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Acs Config List."
2016-04-04T06:58:17.621570      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmLiteSysObject."
2016-04-04T06:58:17.623010      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize dmBatchManager."
2016-04-04T06:58:17.624369      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Partition Scheme."
2016-04-04T06:58:17.627552      21425[21425]    0000000000000000        [DM_SESSION_I_INIT_BEGIN]info:  "Initialize Authentication Plugins."
2016-04-04T06:58:17.631207      21425[21425]    0000000000000000        [DM_SESSION_I_AUTH_PLUGIN_LOADED]info:  "Loaded Authentication Plugin with code 'dm_krb' ($DOCUMENTUM/dba/auth/libkerberos.so)."
2016-04-04T06:58:17.631480      21425[21425]    0000000000000000        [DM_SESSION_I_AUTH_PLUGIN_LOAD_INIT]info:  "Authentication plugin ( 'dm_krb' ) was disabled. This is expected if no keytab file(s) at location ($DOCUMENTUM/dba/auth/kerberos).Please refer the content server installation guide."
2016-04-04T06:58:17.638885      21425[21425]    0000000000000000        [DM_SERVER_I_START_SERVER]info:  "Docbase DOCBASE1 opened"
2016-04-04T06:58:17.639005      21425[21425]    0000000000000000        [DM_SERVER_I_SERVER]info:  "Setting exception handlers to catch all interrupts"
2016-04-04T06:58:17.639043      21425[21425]    0000000000000000        [DM_SERVER_I_START]info:  "Starting server using service name:  DOCBASE1"
2016-04-04T06:58:17.810637      21425[21425]    0000000000000000        [DM_SERVER_I_LAUNCH_MTHDSVR]info:  "Launching Method Server succeeded."
2016-04-04T06:58:17.818319      21425[21425]    0000000000000000        [DM_SERVER_I_LISTENING]info:  "The server is listening on network address (Service Name: DOCBASE1_s, Host Name: content_server_01 :V4 IP)"
2016-04-04T06:58:17.821615      21425[21425]    0000000000000000        [DM_SERVER_I_IPV6_DISABLED]info:  "The server can not listen on IPv6 address because the operating system does not support IPv6"
2016-04-04T06:58:19.301490      21425[21425]    0000000000000000        [DM_WORKFLOW_I_AGENT_START]info:  "Workflow agent master (pid : 21612, session 013f245a80000007) is started sucessfully."
2016-04-04T06:58:19.302601      21425[21425]    0000000000000000        [DM_WORKFLOW_I_AGENT_START]info:  "Workflow agent worker (pid : 21613, session 013f245a8000000a) is started sucessfully."
2016-04-04T06:58:20.304937      21425[21425]    0000000000000000        [DM_WORKFLOW_I_AGENT_START]info:  "Workflow agent worker (pid : 21626, session 013f245a8000000b) is started sucessfully."
2016-04-04T06:58:21.307256      21425[21425]    0000000000000000        [DM_WORKFLOW_I_AGENT_START]info:  "Workflow agent worker (pid : 21639, session 013f245a8000000c) is started sucessfully."
2016-04-04T06:58:22.307448      21425[21425]    0000000000000000        [DM_SERVER_I_START]info:  "Sending Initial Docbroker check-point "
2016-04-04T06:58:22.325337      21425[21425]    0000000000000000        [DM_MQ_I_DAEMON_START]info:  "Message queue daemon (pid : 21655, session 013f245a80000456) is started sucessfully."

 

Ok so this is the first and second pages I got as a result and that’s actually when I realised that the process I was talking about above was in fact the docbase process… So I displayed the third page of the more command and I got the following:

2016-04-05T10:04:28.305238      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_CURSOR_FAIL]error:  "In operation Exec an attempt to create cursor failed; query was: 'SELECT * FROM DM_DOCBASE_CONFIG_RV dm_dbalias_B , DM_DOCBASE_CONFIG_SV dm_dbalias_C  WHERE (dm_dbalias_C.R_OBJECT_ID=:dmb_handle AND dm_dbalias_C.R_OBJECT_ID=dm_dbalias_B.R_OBJECT_ID) ORDER BY dm_dbalias_B.R_OBJECT_ID,dm_dbalias_B.I_POSITION'; error from database system was: ORA-03114: not connected to ORACLE"
2016-04-05T10:04:28.305385      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:04:28.317505      21425[21425]    0000000000000000        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12541: TNS:no listener
2016-04-05T10:04:28.317591      21425[21425]    013f245a80000002        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12541: TNS:no listener
2016-04-05T10:04:58.329725      21425[21425]    0000000000000000        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12541: TNS:no listener
2016-04-05T10:04:58.329884      21425[21425]    013f245a80000002        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12541: TNS:no listener
2016-04-05T10:05:28.339052      21425[21425]    0000000000000000        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12541: TNS:no listener
2016-04-05T10:05:28.339143      21425[21425]    013f245a80000002        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12541: TNS:no listener
2016-04-05T10:05:49.077076      21425[21425]    0000000000000000        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12514: TNS:listener does not currently know of service requested in connect descriptor
2016-04-05T10:05:49.077163      21425[21425]    013f245a80000002        [DM_SESSION_I_RETRYING_DATABASE_CONNECTION]info:  "The following error was encountered trying to get a database connection:  ORA-12514: TNS:listener does not currently know of service requested in connect descriptor
2016-04-05T10:06:23.461495      21425[21425]    013f245a80000002        [DM_SESSION_W_RESTART_AGENT_EXEC]warning:  "The agent exec program has stopped running.  It will be restarted."
2016-04-05T10:06:48.830854      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:11:52.533340      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:16:52.574766      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:21:52.546389      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:26:52.499108      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:31:52.232095      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:36:57.700202      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:42:01.198050      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:47:01.411651      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:52:02.242612      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T10:57:11.886518      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T11:02:13.133405      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"
2016-04-05T11:07:15.364236      21425[21425]    0000000000000000        [DM_OBJ_MGR_E_FETCH_FAIL]error:  "attempt to fetch object with handle 3c3f245a60000210 failed"

 

As you can see above, the first error occurred at “2016-04-05T10:04:28.305385” and that’s actually 0,000147s (=0,1ms) after an error while trying to execute an SQL query on the database for the operation Exec… So this must be linked… The database errors stopped one minute after the first one so the DB was available again. I quickly verified that using sqlplus.

 

We opened a SR on the EMC website to work on it with them but as far as I know, no solution were found. The only workaround that we found is that a simple restart of the docbase will cleanup these errors from the docbase log file and they will not appear afterwards but that’s pretty annoying to restart the docbase while it is actually working properly (jobs are running, dfc clients are OK, aso…) just because there is one error message printed every 5 minutes in the log file that is flooding our monitoring tool.

 

The problem with this error is that it can happen frequently if the Network isn’t really reliable, if the Database Listener isn’t always responsive or if anything else prevent Documentum from reaching the Database while it is doing something with the dm_docbase_config objects… Something that we didn’t try yet is to re-initialize the Content Server, to see if it can help to restore a proper log file. I think I’m gonna try that next time this issue occurs!

Edit: Re-initialize the Content Server isn’t helping :(.

Post Views: 1,035
Thumbnail [60x60]
by
Morgan Patou