Infrastructure at your Service

As part of the same migration & upgrade project I talked about in previous blogs already (corrupt lockbox, duplicate objects & wrong target_server), I have seen a very annoying and, this time, absolutely not consistent behavior in some upgrade from Documentum 7.x to 16.x versions. The issue or rather the issues I had was that random DAR files were not installed properly. This makes it rather difficult to anticipate since you basically don’t know what might fail before you actually do it for real. Performing DryRun helps a lot in anticipating potential (recurring) problems but if the issue itself is random, there isn’t much you can do without some gifts (if you can see the future, please reach out to me!)…

 

In the past couple months, I performed around a dozen {migration+upgrade} and about half of these had issues with random DARs installation during the upgrade process. Even a DryRun and a real execution of the exact same procedure using the exact same source system ended-up with two different results: one worked without issue (the real migration fortunately) while the DryRun ended-up with a missing dar. In the procedure, it is checked whether or not there are any locks on repository objects, whether there are inconsistencies, whether there are any tasks in progress, aso…

 

Issues were mostly linked to the following few DARs:

  • LDAP.dar
  • MessagingApp.dar
  • MailApp.dar

 

I. LDAP

First, regarding the LDAP dar file, it only happened once and it was pretty easy to spot. As part of the migrations, I had to change the LDAP Server used. Since the target system was on Kubernetes using complete CI/CD, we automated the creation of the LDAP Config Object with all its parameters but this piece failed for one of the migration. Replicating the issue showed the following outcome:

[[email protected]_cs ~]$ iapi REPO1
Please enter a user (dmadmin):
Please enter password for dmadmin:

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

Connecting to Server using docbase REPO1
[DM_SESSION_I_SESSION_START]info:  "Session 010f123450262d3b started for user dmadmin."

Connected to OpenText Documentum Server running Release 16.4.0170.0234  Linux64.Oracle
Session id is s0
API> ?,c,select r_object_id, object_name from dm_ldap_config
r_object_id       object_name
----------------  ------------------------
(0 rows affected)

API> create,c,dm_ldap_config
...
[DM_DFC_E_CLASS_NOT_FOUND]error:  "Unable to instantiate the necessary java class: com.documentum.ldap.impl.DfLdapConfig"

java.lang.ClassNotFoundException: com.documentum.ldap.impl.DfLdapConfig

com.documentum.thirdparty.javassist.NotFoundException: com.documentum.ldap.impl.DfLdapConfig


API> ?,c,SELECT r_object_id, r_modify_date, object_name FROM dmc_dar ORDER BY r_modify_date ASC;
r_object_id       r_modify_date              object_name
----------------  -------------------------  ------------------------
080f1234500007a5  12/1/2018 09:05:30         LDAP
080f12345086063d  2/12/2020 16:26:12         Smart Container
080f123450860780  2/12/2020 16:26:44         Webtop
080f1234508607a1  2/12/2020 16:26:59         Workflow
080f1234508607f9  2/12/2020 16:27:34         Presets
...

API> exit
Bye
[[email protected]_cs ~]$

 

This kind of error ([DM_DFC_E_CLASS_NOT_FOUND]error: “Unable to instantiate the necessary java class: com.documentum.ldap.impl.DfLdapConfig”) can happen when the LDAP dar isn’t installed properly. In this case, during the upgrade it was indeed what happened, the current DAR seemed to be from the source system before the upgrade (r_modify_date is much older). The DAR installation log file generated by the upgrade shows that the LDAP one was skipped:

[[email protected]_cs ~]$ grep "\[ERR" $DOCUMENTUM/dba/config/REPO1/dars.log
[ERROR]  A module 'IDfLdapConfigModule' already exists under folder 'IDfLdapConfigModule'.
[[email protected]_cs ~]$

 

After re-install of the LDAP dar, the issue was resolved.

 

II. MessagingApp

Then regarding the MessagingApp dar file, this one also only happened once and it was very strange… While doing sanity checks after the end of the migration, everything was working except for searches from a client application like DA or D2. From the repository itself, full text searches were working properly:

API> ?,c,SELECT r_object_id, object_name FROM dm_document SEARCH document contains 'TestDocument';
r_object_id       object_name
----------------  --------------------
090f2345600731d6  TestDoc.pdf
(1 row affected)

 

However, doing the same kind of search on D2 for example showed something completely different:

2020-03-03 10:30:55,750 UTC [INFO ] ([ACTIVE] ExecuteThread: '70' for queue: 'weblogic.kernel.Default (self-tuning)') - c.e.x3.server.services.RpcDoclistServiceImpl  : Context REPO2-1583231056848-dmadmin-2003987903 with terms = TestDocument
2020-03-03 10:30:55,751 UTC [DEBUG] ([ACTIVE] ExecuteThread: '70' for queue: 'weblogic.kernel.Default (self-tuning)') - c.emc.d2fs.dctm.aspects.InjectSessionAspect   : Call first service D2SearchService.getQuickSearchContentWithOption(..)
2020-03-03 10:30:55,751 UTC [DEBUG] ([ACTIVE] ExecuteThread: '70' for queue: 'weblogic.kernel.Default (self-tuning)') - c.emc.d2fs.dctm.aspects.InjectSessionAspect   : InjectSessionAspect::process method: com.emc.d2fs.dctm.web.services.search.D2SearchService.getQuickSearchContentWithOption
...
...
2020-03-03 10:31:01,289 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.common.dctm.queries.D2QueryBuilder    : Query History: IDfQueryEvent(INTERNAL, DEFAULT): [REPO2] returned [Start processing] at [2020-03-03 10:30:56:007 +0000]
IDfQueryEvent(ERROR, UNKNOWN): [REPO2] returned [[DM_VEL_INSTANTIATION_ERROR]error:  "Cannot instantiate Java class"] at [2020-03-03 10:31:01:280 +0000]
DfServiceInstantiationException:: THREAD: Search Broker:REPO2:processing started at Tue Mar 03 10:30:55 UTC 2020; MSG: [DM_VEL_INSTANTIATION_ERROR]error:  "Cannot instantiate Java class"; ERRORCODE: 1902; NEXT: null
        at com.documentum.fc.client.impl.bof.classmgmt.ModuleManager.loadModuleClass(ModuleManager.java:258)
        at com.documentum.fc.client.impl.bof.classmgmt.ModuleManager.getModuleClass(ModuleManager.java:203)
        at com.documentum.fc.client.impl.bof.classmgmt.ModuleManager.newModule(ModuleManager.java:154)
        at com.documentum.fc.client.impl.bof.classmgmt.ModuleManager.newModule(ModuleManager.java:86)
        at com.documentum.fc.client.impl.bof.classmgmt.ModuleManager.newModule(ModuleManager.java:60)
        at com.documentum.fc.client.DfClient$ClientImpl.newModule(DfClient.java:466)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.ComplexMappingDefinitionManager.getMappingModule(ComplexMappingDefinitionManager.java:352)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.ComplexMappingDefinitionManager.getComplexMappingDefinitionFromDocbase(ComplexMappingDefinitionManager.java:319)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.ComplexMappingDefinitionManager.loadComplexMappingDefinition(ComplexMappingDefinitionManager.java:149)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.ComplexMappingDefinitionManager.getComplexMappingDefinition(ComplexMappingDefinitionManager.java:75)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.loading.legacy.LegacyMappingLoader.loadSearchInterfaces(LegacyMappingLoader.java:42)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.EosMappingLoader.populateLegacyMapping(EosMappingLoader.java:199)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.EosMappingLoader.populateMappingCache(EosMappingLoader.java:112)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.definition.EosMappingLoader.getInterface(EosMappingLoader.java:63)
        at com.documentum.fc.client.search.impl.generation.docbase.common.sco.mapping.SCOGenerator.isComplexQuery(SCOGenerator.java:38)
        at com.documentum.fc.client.search.impl.generation.docbase.TargetLanguageSelector.initByQueryBuilder(TargetLanguageSelector.java:85)
        at com.documentum.fc.client.search.impl.generation.docbase.TargetLanguageSelector.<init>(TargetLanguageSelector.java:39)
        at com.documentum.fc.client.search.impl.generation.docbase.DocbaseQueryGeneratorManager.generateQueryExecutor(DocbaseQueryGeneratorManager.java:248)
        at com.documentum.fc.client.search.impl.generation.docbase.DocbaseQueryGeneratorManager.generateQueryExecutor(DocbaseQueryGeneratorManager.java:96)
        at com.documentum.fc.client.search.impl.execution.adapter.docbase.DocbaseAdapter.execute(DocbaseAdapter.java:83)
        at com.documentum.fc.client.search.impl.execution.broker.SearchJob.handleProcessingState(SearchJob.java:382)
        at com.documentum.fc.client.search.impl.execution.broker.SearchJob.doRunLoop(SearchJob.java:477)
        at com.documentum.fc.client.search.impl.execution.broker.SearchJob.run(SearchJob.java:433)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ClassNotFoundException: com.documentum.services.complexobjects.impl.ComplexObjectMappingDefImpl
        at java.net.URLClassLoader.findClass(URLClassLoader.java:382)
        at com.documentum.fc.client.impl.bof.classmgmt.URLClassLoaderEx.findClass(URLClassLoaderEx.java:49)
        at com.documentum.fc.client.impl.bof.classmgmt.DelayedDelegationClassLoader.findClass(DelayedDelegationClassLoader.java:241)
        at com.documentum.fc.client.impl.bof.classmgmt.AbstractTransformingClassLoader.findClass(AbstractTransformingClassLoader.java:122)
        at com.documentum.fc.client.impl.bof.classmgmt.DelayedDelegationClassLoader.loadClass(DelayedDelegationClassLoader.java:147)
        at com.documentum.fc.client.impl.bof.classmgmt.AbstractTransformingClassLoader.loadClass(AbstractTransformingClassLoader.java:69)
        at com.documentum.fc.client.impl.bof.classmgmt.ModuleManager.loadModuleClass(ModuleManager.java:254)
        ... 25 more

IDfQueryEvent(ERROR, UNREACHABLE): [REPO2] returned [Unable to process query] at [2020-03-03 10:31:01:281 +0000]
, Query Status: 6
2020-03-03 10:31:01,291 UTC [ERROR] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.common.dctm.queries.D2QueryBuilder    : The search has failed. null
2020-03-03 10:31:01,307 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Executing xPlore search ended : 6.722s
2020-03-03 10:31:01,307 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Enter buildItems
2020-03-03 10:31:01,308 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : FACETS: ObjectID = 080f2345602f4a20
2020-03-03 10:31:01,310 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : listColNames=[object_name, score, title, a_status, r_modify_date, r_modifier]
2020-03-03 10:31:01,311 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Exit buildItems
2020-03-03 10:31:01,311 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : FACETS: leaving getContent
2020-03-03 10:31:01,354 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : getSearchContent - start building facets
2020-03-03 10:31:01,355 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Exit buildFacets
2020-03-03 10:31:01,355 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Query name = lastSearch
2020-03-03 10:31:01,363 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Enter getObjectName
2020-03-03 10:31:01,364 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Exit getObjectName
2020-03-03 10:31:01,364 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : FACETS: attrNameList from query = []
2020-03-03 10:31:01,364 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : FACETS: attrValueList from query = []
2020-03-03 10:31:01,365 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : searchTypes = [dm_document]
2020-03-03 10:31:01,365 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : getSearchContent - done building facets
2020-03-03 10:31:01,365 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.content.D2cQueryContent     : Exit getSearchContent
2020-03-03 10:31:01,366 UTC [ERROR] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - c.emc.d2fs.dctm.aspects.InjectSessionAspect   : {}
com.documentum.fc.common.DfException: The search has failed.
[DM_VEL_INSTANTIATION_ERROR]
        at com.emc.d2fs.dctm.content.D2cQueryContent.getSearchContent(D2cQueryContent.java:598)
        at com.emc.d2fs.dctm.content.NodeLastSearchContent.getSearchContent(NodeLastSearchContent.java:217)
        at com.emc.d2fs.dctm.web.services.content.D2ContentService.getContent(D2ContentService.java:391)
        at com.emc.d2fs.dctm.web.services.content.D2ContentService.getSearchContent_aroundBody14(D2ContentService.java:425)
        at com.emc.d2fs.dctm.web.services.content.D2ContentService$AjcClosure15.run(D2ContentService.java:1)
        at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:229)
        at com.emc.d2fs.dctm.aspects.InjectSessionAspect.process(InjectSessionAspect.java:240)
        at com.emc.d2fs.dctm.web.services.content.D2ContentService.getSearchContent(D2ContentService.java:403)
        at com.emc.x3.client.services.search.RpcSearchManagerServiceImpl.getSearchResults(RpcSearchManagerServiceImpl.java:37)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:587)
        at com.emc.x3.server.GuiceRemoteServiceServlet.processCall(GuiceRemoteServiceServlet.java:105)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:373)
        at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263)
        at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178)
        at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
        at com.custom.d2.auth.filters.NonSSOAuthenticationFilter.executeChain(NonSSOAuthenticationFilter.java:33)
        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
        at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
        at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
        at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
        at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
        at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
        at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118)
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113)
        at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
        at com.emc.x3.portal.server.filters.X3SessionTimeoutFilter.doFilter(X3SessionTimeoutFilter.java:40)
        at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
        at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3706)
        at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3672)
        at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:328)
        at weblogic.security.service.SecurityManager.runAsForUserCode(SecurityManager.java:197)
        at weblogic.servlet.provider.WlsSecurityProvider.runAsForUserCode(WlsSecurityProvider.java:203)
        at weblogic.servlet.provider.WlsSubjectHandle.run(WlsSubjectHandle.java:71)
        at weblogic.servlet.internal.WebAppServletContext.doSecuredExecute(WebAppServletContext.java:2443)
        at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2291)
        at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2269)
        at weblogic.servlet.internal.ServletRequestImpl.runInternal(ServletRequestImpl.java:1705)
        at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1665)
        at weblogic.servlet.provider.ContainerSupportProviderImpl$WlsRequestExecutor.run(ContainerSupportProviderImpl.java:272)
        at weblogic.invocation.ComponentInvocationContextManager._runAs(ComponentInvocationContextManager.java:352)
        at weblogic.invocation.ComponentInvocationContextManager.runAs(ComponentInvocationContextManager.java:337)
        at weblogic.work.LivePartitionUtility.doRunWorkUnderContext(LivePartitionUtility.java:57)
        at weblogic.work.PartitionUtility.runWorkUnderContext(PartitionUtility.java:41)
        at weblogic.work.SelfTuningWorkManagerImpl.runWorkUnderContext(SelfTuningWorkManagerImpl.java:652)
        at weblogic.work.ExecuteThread.execute(ExecuteThread.java:420)
        at weblogic.work.ExecuteThread.run(ExecuteThread.java:360)
2020-03-03 10:31:01,366 UTC [DEBUG] ([ACTIVE] ExecuteThread: '76' for queue: 'weblogic.kernel.Default (self-tuning)') - com.emc.d2fs.dctm.web.services.D2fsContext    : Release session : s1

 

As you can see above, D2 complains about instantiation of a specific class (“com.documentum.services.complexobjects.impl.ComplexObjectMappingDefImpl”). This class is part of an SBO bundled in the MessagingApp.dar as mentioned on KB6289567 & KB6296577.

 

Therefore, the DAR installation must have failed, right? Well it didn’t and that’s the strange thing I was talking about… I have the evidences of the proper installation of the MessagingApp.dar inside the repository the day before:

[INFO]  ******************************************************
[INFO]  * Headless Composer
[INFO]  * Version:        16.4.000.0042
[INFO]  * Java version:   1.8.0_152 (64bit)
[INFO]  * Java home:      $JAVA_HOME/jre
[INFO]  * Set storage type: false
[INFO]  *
[INFO]  * DAR file:       $DOCUMENTUM/product/16.4/install/DARsInternal/MessagingApp.dar
[INFO]  * Project name:   MessagingApp
[INFO]  * Built by Composer: 7.1.0000.0186
[INFO]  *
[INFO]  * Repository:     REPO2
[INFO]  * Server version: 16.4.0170.0234  Linux64.Oracle
[INFO]  * User name:      dmadmin
[INFO]  ******************************************************
[INFO]  Install started...  Mon Mar 02 22:18:00 UTC 2020
[INFO]  Executing pre-install script
[INFO]  Pre-install script executed successfully Mon Mar 02 22:18:00 UTC 2020
...
[INFO]  Done Overwriting object : 'com.documentum.services.complexobjects.impl.ComplexObjectMappingDefImpl'(dmc_module 0b0f2345600008f9)
...
[INFO]  Done Versioning object : 'MessagingApp'(dmc_dar 080f2345608608e9)
...
[INFO]  Finished executing post-install actions Mon Mar 02 22:18:30 UTC 2020
[INFO]  Finished executing post-install script Mon Mar 02 22:18:32 UTC 2020
[INFO]  Project 'MessagingApp' was successfully installed.

 

There are absolutely no errors and it shows that the missing class “com.documentum.services.complexobjects.impl.ComplexObjectMappingDefImpl” was upgraded properly but on D2, it doesn’t work (it was properly installed on both the Global Registry and the Repository used for the search). Re-installing again the DAR file produced exactly the same log file: 100% the same except for the date, obviously. After the re-installation of the DAR, the issue was magically gone. For this issue honestly, I’m still amazed how this can be possible and I’m pretty sure I will never find any reason.

 

III. MailApp

Finally, the last issue is with the MailApp dar file. That’s the one which had the most occurrences as far as I could see. During an upgrade from 7.3 to 16.4 P17, the dar installation failed and the following was shown inside the “dars.log” file:

[INFO]  ******************************************************
[INFO]  * Headless Composer
[INFO]  * Version:        16.4.000.0042
[INFO]  * Java version:   1.8.0_152 (64bit)
[INFO]  * Java home:      $JAVA_HOME/jre
[INFO]  * Set storage type: false
[INFO]  *
[INFO]  * DAR file:       $DOCUMENTUM/product/16.4/install/DARsInternal/MailApp.dar
[INFO]  * Project name:   MailApp
[INFO]  * Built by Composer: 7.1.0000.0186
[INFO]  *
[INFO]  * Repository:     REPO3
[INFO]  * Server version: 16.4.0170.0234  Linux64.Oracle
[INFO]  * User name:      dmadmin
[INFO]  ******************************************************
[INFO]  Install started...  Thu Mar 12 10:08:27 UTC 2020
[INFO]  Executing pre-install script
[INFO]  dmbasic.exe output : connecting docbase...REPO3
[INFO]  dmbasic.exe output : dm_attachment_folder type exists
[INFO]  dmbasic.exe output : Relation type 'dm_attachments_relation' already exists
[INFO]  dmbasic.exe output : Disconnect from the docbase.
[INFO]  Pre-install script executed successfully Thu Mar 12 10:08:31 UTC 2020
[WARN]  Cannot retrieve object by Object Id. This may happen if an object previously installed by Composer was deleted. Object reference will be returned as null. OID: 0b0f345670000df1, URN: urnd:com.emc.ide.artifact.moduledef/com.documentum.mailapp.operations.DfPreProcessMessageObject?artifactURI=file:/C:/Source/.../com.documentum.mailapp.operations.dfpreprocessmessageobject.module#//@dataModel/@externalInterfaces
[WARN]  Cannot retrieve object by Object Id. This may happen if an object previously installed by Composer was deleted. Object reference will be returned as null. OID: 0b0f345670000fe9, URN: urnd:com.emc.ide.artifact.aspectmoduledef/dm_attachmentfolder_aspect?artifactURI=file:/C:/Source/.../dm_attachmentfolder_aspect.module#//@dataModel/@miscellaneous
[WARN]  Cannot retrieve object by Object Id. This may happen if an object previously installed by Composer was deleted. Object reference will be returned as null. OID: 090f345670000e37, URN: urnd:com.emc.ide.artifact.jardef.jardef/attachmentfolderaspect.jar?artifactURI=file:/C:/source/.../attachmentfolderaspect.jar%5B1%5D.jardef#//@dataModel
[WARN]  Cannot retrieve object by Object Id. This may happen if an object previously installed by Composer was deleted. Object reference will be returned as null. OID: 080f345670000e41, URN: urnd:com.emc.ide.artifact.moduledef/com.message.aspose?artifactURI=file:/C:/Users/.../com.message.aspose.module#//@dataModel/@runtimeEnvironmentXML
[ERROR]  A module 'dm_attachmentfolder_aspect' already exists under folder 'Aspect'.
[ERROR]  A module 'mdmo_message_aspect' already exists under folder 'Aspect'.
[WARN]  superTypeName is null. This might happen if the dependent project is not Installed in the same ANT build invocation
[ERROR]  A module 'com.documentum.mailapp.operations.DfPreProcessMessageObject' already exists under folder 'Operations'.
[ERROR]  A module 'com.documentum.mailapp.operations.inbound.DfCleanUpLocalMailAppFiles' already exists under folder 'Operations'.
[ERROR]  A module 'com.documentum.mailapp.operations.inbound.DfFixUpAttachments' already exists under folder 'Operations'.
[ERROR]  A module 'com.documentum.mailapp.operations.inbound.DfImportMailObject' already exists under folder 'Operations'.
[ERROR]  A module 'com.documentum.mailapp.operations.inbound.DfSeparateAttachments' already exists under folder 'Operations'.
[ERROR]  A module 'aspose' already exists under folder 'Modules'.
[ERROR]  A module 'mailappconfig' already exists under folder 'Modules'.
[INFO]  MailApp install aborted by user.

 

On another migration with a source that is 7.2 this time and a target that is 16.4 P20, we had another batch of issues. On 7.2, the MailApp didn’t exist (as far as I know), so the upgrade is supposed to install for the first time this DAR but it fails because some of the pieces already exists. If you look at the logs above, the same type existed already as well but above, it just continued without any problem the “Pre-install” script (line 19, 22 above // line 20, 22 below). Below, it fails on already existing types and in both cases [above for 7.3 and below for 7.2], the flag “preserve_existing_types” is set to “T” (True) in the server.ini of all repositories so it doesn’t make much sense that there is a difference in behavior… However, that’s how it is so if you have any explanation, feel free to share! I asked OpenText to look into it but nothing came out of it so far. Anyway, so here are the logs on the 7.2 repository:

[INFO]  ******************************************************
[INFO]  * Headless Composer
[INFO]  * Version:        16.4.000.0042
[INFO]  * Java version:   1.8.0_152 (64bit)
[INFO]  * Java home:      $JAVA_HOME/jre
[INFO]  * Set storage type: false
[INFO]  *
[INFO]  * DAR file:       $DOCUMENTUM/product/16.4/install/DARsInternal/MailApp.dar
[INFO]  * Project name:   MailApp
[INFO]  * Built by Composer: 7.1.0000.0186
[INFO]  *
[INFO]  * Repository:     REPO4
[INFO]  * Server version: 16.4.0200.0256  Linux64.Oracle
[INFO]  * User name:      dmadmin
[INFO]  ******************************************************
[INFO]  Install started...  Fri Apr 03 08:32:45 UTC 2020
[INFO]  Executing pre-install script
[INFO]  dmbasic.exe output : connecting docbase...REPO4
[INFO]  dmbasic.exe output : Create dm_state_extension type.
[INFO]  dmbasic.exe output : [DM_QUERY_E_CREATE_FAILED]error:  "CREATE TYPE statement failed for type: dm_attachment_folder."
[INFO]  dmbasic.exe output :
[INFO]  dmbasic.exe output : [DM_TYPE_MGR_E_EXISTING_TABLE]error:  "Cannot create type dm_attachment_folder because the table dm_attachment_folder_s unexpectedly already exists in the database and the server 'preserve_existing_types' flag is enabled.  To complete this operation the table must first be manually dropped or the server flag disabled."
[INFO]  dmbasic.exe output :
[INFO]  dmbasic.exe output :
[INFO]  dmbasic.exe output : Failed to create dm_attachment_folder type
[ERROR]  Procedure execution failed with dmbasic.exe exit value : 255
[INFO]  MailApp install failed.
[ERROR]  Unable to install dar file $DOCUMENTUM/product/16.4/install/DARsInternal/MailApp.dar
com.emc.ide.installer.PreInstallException: Error running pre-install procedure "presetup". Please contact the procedure owner to verify if it is functioning properly. Please also check if the JAVA_HOME is pointing to the correct JDK. In case of multiple installed JDK's, please provide -vm <JDK>bin flag in the composer.ini/dardeployer.ini files
        at internal.com.emc.ide.installer.DarInstaller.preInstall(DarInstaller.java:1085)
        at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:495)
        at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:334)
        at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:303)
        at com.emc.ide.installer.util.IDarInstallerHelper.doInPlaceInstall(IDarInstallerHelper.java:127)
        at com.emc.ant.installer.api.InstallerAntTask.installDar(InstallerAntTask.java:258)
        at com.emc.ant.installer.api.InstallerAntTask.execute(InstallerAntTask.java:135)
        at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:291)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:106)
        at org.apache.tools.ant.Task.perform(Task.java:348)
        at org.apache.tools.ant.Target.execute(Target.java:392)
        at org.apache.tools.ant.Target.performTasks(Target.java:413)
        at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1399)
        at org.apache.tools.ant.Project.executeTarget(Project.java:1368)
        at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:41)
        at org.eclipse.ant.internal.core.ant.EclipseDefaultExecutor.executeTargets(EclipseDefaultExecutor.java:32)
        at org.apache.tools.ant.Project.executeTargets(Project.java:1251)
        at org.eclipse.ant.internal.core.ant.InternalAntRunner.run(InternalAntRunner.java:672)
        at org.eclipse.ant.internal.core.ant.InternalAntRunner.run(InternalAntRunner.java:537)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.ant.core.AntRunner.run(AntRunner.java:513)
        at org.eclipse.ant.core.AntRunner.start(AntRunner.java:600)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:353)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:180)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:629)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:584)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1438)
        at org.eclipse.equinox.launcher.Main.main(Main.java:1414)
        at org.eclipse.core.launcher.Main.main(Main.java:34)
Caused by: com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerException: Procedure execution failed with dmbasic.exe exit value : 255
        at com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerUtils.executeDmBasic(ProcedureRunnerUtils.java:283)
        at com.emc.ide.external.dfc.procedurerunner.ProcedureRunner.execute(ProcedureRunner.java:55)
        at internal.com.emc.ide.installer.DarInstaller.preInstall(DarInstaller.java:1080)
        ... 42 more
[ERROR]  Failed to install DAR
Unable to install dar file $DOCUMENTUM/product/16.4/install/DARsInternal/MailApp.dar
        at com.emc.ant.installer.api.InstallerAntTask.installDar(InstallerAntTask.java:273)
        at com.emc.ant.installer.api.InstallerAntTask.execute(InstallerAntTask.java:135)
        at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:291)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:106)
        at org.apache.tools.ant.Task.perform(Task.java:348)
        at org.apache.tools.ant.Target.execute(Target.java:392)
        at org.apache.tools.ant.Target.performTasks(Target.java:413)
        at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1399)
        at org.apache.tools.ant.Project.executeTarget(Project.java:1368)
        at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:41)
        at org.eclipse.ant.internal.core.ant.EclipseDefaultExecutor.executeTargets(EclipseDefaultExecutor.java:32)
        at org.apache.tools.ant.Project.executeTargets(Project.java:1251)
        at org.eclipse.ant.internal.core.ant.InternalAntRunner.run(InternalAntRunner.java:672)
        at org.eclipse.ant.internal.core.ant.InternalAntRunner.run(InternalAntRunner.java:537)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.ant.core.AntRunner.run(AntRunner.java:513)
        at org.eclipse.ant.core.AntRunner.start(AntRunner.java:600)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:353)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:180)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:629)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:584)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1438)
        at org.eclipse.equinox.launcher.Main.main(Main.java:1414)
        at org.eclipse.core.launcher.Main.main(Main.java:34)
Caused by: com.emc.ide.installer.PreInstallException: Error running pre-install procedure "presetup". Please contact the procedure owner to verify if it is functioning properly. Please also check if the JAVA_HOME is pointing to the correct JDK. In case of multiple installed JDK's, please provide -vm <JDK>bin flag in the composer.ini/dardeployer.ini files
        at internal.com.emc.ide.installer.DarInstaller.preInstall(DarInstaller.java:1085)
        at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:495)
        at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:334)
        at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:303)
        at com.emc.ide.installer.util.IDarInstallerHelper.doInPlaceInstall(IDarInstallerHelper.java:127)
        at com.emc.ant.installer.api.InstallerAntTask.installDar(InstallerAntTask.java:258)
        ... 37 more
Caused by: com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerException: Procedure execution failed with dmbasic.exe exit value : 255
        at com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerUtils.executeDmBasic(ProcedureRunnerUtils.java:283)
        at com.emc.ide.external.dfc.procedurerunner.ProcedureRunner.execute(ProcedureRunner.java:55)
        at internal.com.emc.ide.installer.DarInstaller.preInstall(DarInstaller.java:1080)
        ... 42 more

 

If you have the above errors, you can just set the “preserve_existing_types” flag to “F” (False), then start again the DAR installation and it should be installing properly this time. Please take care with this flag! If you are copying the repository, it must be set to “T” (True) otherwise it will most likely cause you big troubles… But for in-place upgrade, you can and should set it to “F” (False) before starting the repository upgrade and switch it back to “T” (True) once the upgrade is completed and all DARs have been installed. So make sure you do that and the number of issues during DAR installations should decrease drastically.

 

Anyway, all that to say that there are some best practices to apply to upgrade, even if it’s not documented anywhere. In addition, you should be careful about the DARs installation logs and really test your application because even when everything seems to went well, you might not be completely safe… Where would be the fun if you could rely on deterministic systems? 😉

 

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Morgan Patou
Morgan Patou

Senior Consultant & Technology Leader ECM