Feed aggregator
APEX Error 572 autopsy
A couple of days ago I exported an application from APEX 24.1.5 and imported it into APEX 24.2.9 on my OCI free tier instance.
Whilst the application itself was working fine, I got a problem when I tried to edit page 4 in the App Builder: the spinner kept spinning for an unusual amount of time and eventually stopped showing an empty page, and in the error notification area APEX showed "Error: 572".
Now, according to other users this Error 572 was a symptom of an overloaded database, which seemed strange to me because the page is not particularly complex and I could open other pages in the editor without problems.
After various unsuccessful attempts to see if I could gather some meaningful information from the APEX Builder debug logs (see this interesting Steve Muench's blog posting on how to do that), I decided to have a closer look at the differences between the previous version of this page and the current, problematic one.
Here are some relevant facts:
- The current version of the page can be edited without problems in APEX 24.1.5.
- If I export this single page from 24.1.5 and import into 24.2.9 the problem persists, so if there is a problem, it's not caused by the import process of the whole application.
- The "new" version of the page works correctly when I run the application, so, APEX metadata must be good.
- The only difference between the old version and the new version is in the source of the query I am using to populate an Interactive Report.
- If I import the old version of the page, then the App Builder editor resumes working properly.
The difference between the old and the new query is the following CASE function, the old version did not contain the lines in yellow:
case
when json_value(e.value,'$.email[0]') is null
then apex_lang.message('NO_RECIPIENT')
when json_value(e.value,'$.email[1]') is null
then apex_lang.message('SINGLE_RECIPIENT')
else apex_lang.message('OTHER_RECIPIENTS')
end as RECIPIENTSIf I comment out the two lines in yellow in the page source, import the page and try to edit it, everything is back to normal.
The tricky part in this type of problems is in that if you receive this error upon entering the editor then you cannot delete the offending page because Error code 572 is breaking the delete page functionality, so your only option is to replace the page with an import of a working version.
If you receive this error while you are still inside the editor of the page, you may have a chance of reverting the page to its previous state.
In my case it was easy, I had an older working version of the page, but if you don't, then you must work around the problem in some other fashion, in the worst case I presume you must edit the import file and get rid of some components.
In conclusion, my wild guess is that something wrong is happening at parse time and in particular I strongly suspect that the absence of meaningful values for the bind variables used in the conditions of my query are breaking the logic of the JSON_VALUE function that relies on the content of the JSON array "email", which at parse time of course is empty, resulting in this weird error.
Moreover, the IR query handling must have changed in some way between the two APEX releases.
Now, it could be that Error 572 is also returned when there is a "database overload", but in this specific case I can't see any correlation.
Or may be there is something else going on that I can't fathom right now.
Tip of the day: hide (or show) multiple buttons or other page components with a single dynamic action
Need to hide or show multiple buttons or page items basing on a common client-side condition?
Instead of creating a single dynamic action for each button, define a common CSS class (i.e. mybuttons) on each of the buttons and then use a single DA with jQuery selector like ".mybuttons" for the Hide action and one for the Show action, thus reducing the page complexity.
And you can also extend this to other components like page items or regions, if they follow the same logic.
Natural Sort in SQL
To sort strings in SQL is fairly straightforward:
select * from mytable order by name;This uses the default collation which is at its core based on a character-by-character comparison, which almost always matches what humans would consider to be the “right” order – unless decimal numbers are found, in which case this will sort strings like ‘abc-2000’ before ‘abc-30’.
Natural Sort, on the other hand, compares strings using a more complex algorithm that finds embedded decimal numbers and sorts them according to their numeric value.
I’ve taken the algorithm from https://github.com/sourcefrog/natsort and implemented it in PL/SQL:
create or replace type natural_sort as object (
v varchar2(32767),
order member function compare(p_other natural_sort) return integer
);
/
create or replace type body natural_sort as
order member function compare(p_other natural_sort) return integer is
function is_whitespace(a in char) return boolean is
begin
return a is not null and ascii(a) <= 32;
end is_whitespace;
function is_digit(a in char) return boolean is
begin
return a is not null and ascii(a) between 48 and 57;
end is_digit;
function compare_right(a in varchar2, b in varchar2) return number is
bias number := 0;
ia number := 0;
ib number := 0;
ca char(1 char);
cb char(1 char);
begin
-- The longest run of digits wins. That aside, the greatest
-- value wins, but we can't know that it will until we've scanned
-- both numbers to know that they have the same magnitude, so we
-- remember it in bias.
loop
ca := substr(a, ia, 1);
cb := substr(b, ib, 1);
pragma inline (is_digit, 'yes');
if not is_digit(ca) and not is_digit(cb) then
return bias;
pragma inline (is_digit, 'yes');
elsif not is_digit(ca) then
return -1;
pragma inline (is_digit, 'yes');
elsif not is_digit(cb) then
return 1;
elsif ca < cb then
if bias = 0 then
bias := -1;
end if;
elsif ca > cb then
if bias = 0 then
bias := 1;
end if;
elsif ca = 0 and cb = 0 then
return bias;
end if;
ia := ia + 1;
ib := ib + 1;
end loop;
end compare_right;
function natcompare(a in varchar2, b in varchar2) return number is
ia number := 0;
ib number := 0;
nza number;
nzb number;
ca char(1 char);
cb char(1 char);
ret number;
begin
loop
-- only count the number of zeroes leading the last number compared
nza := 0;
nzb := 0;
ca := substr(a, ia, 1);
cb := substr(b, ib, 1);
-- skip over leading spaces or zeros
pragma inline (is_whitespace, 'yes');
while is_whitespace( ca ) or ca = '0' loop
if ca = '0' then
nza := nza + 1;
else
-- only count consecutive zeroes
nza := 0;
end if;
ia := ia + 1;
ca := substr(a, ia, 1);
end loop;
pragma inline (is_whitespace, 'yes');
while is_whitespace( cb ) or cb = '0' loop
if cb = '0' then
nzb := nzb + 1;
else
-- only count consecutive zeroes
nzb := 0;
end if;
ib := ib + 1;
cb := substr(b, ib, 1);
end loop;
if ca is null and cb is null then
-- The strings compare the same. Break the tie with the
-- default comparison.
if a < b then
return -1;
elsif a > b then
return 1;
end if;
end if;
-- process run of digits
pragma inline (is_digit, 'yes');
if is_digit(ca) and is_digit(cb) then
ret := compare_right(substr(a, ia), substr(b, ib));
if ret != 0 then
return ret;
end if;
end if;
if ca < cb then
return -1;
elsif ca > cb then
return 1;
end if;
ia := ia + 1;
ib := ib + 1;
end loop;
end natcompare;
begin
if v is null and p_other.v is null then
return 0;
elsif v is null and p_other.v is not null then
return 1;
elsif v is not null and p_other.v is null then
return -1;
elsif v = p_other.v then
return 0;
end if;
return natcompare(v, p_other.v);
end compare;
end;
/
This creates a type in the schema called natural_sort which can be used in SQL and PL/SQL very simply, e.g.:
select * from my_table order by natural_sort(name);This is my test script:
select * from apex_string.split( q'[
fred
pic2
pic100a
pic120
pic121
jane
tom
pic02a
pic3
pic4
1-20
pic100
pic02000
10-20
1-02
1-2
x2-y7
x8-y8
x2-y08
x2-g8
pic01
pic02
pic 6
pic 7
pic 5
pic05
pic 5
pic 5 something
pic 4 else
1.001
1.2
1.002
1.02
1.09
1.101
1.102
1.010
1.10
1.200
1.199
1.198
1.1
2000-1-10
2000-1-2
1999-12-25
2000-3-23
1999-3-3
]' )
order by natural_sort(column_value);The result of the above test query is:
1-02
1-2
1-20
1.001
1.1
1.002
1.02
1.2
1.09
1.010
1.10
1.101
1.102
1.198
1.199
1.200
10-20
1999-3-3
1999-12-25
2000-1-2
2000-1-10
2000-3-23
fred
jane
pic01
pic02
pic02a
pic2
pic3
pic 4 else
pic4
pic 5
pic 5
pic 5 something
pic05
pic 6
pic 7
pic100
pic100a
pic120
pic121
pic02000
tom
x2-g8
x2-y7
x2-y08
x8-y8Warning: this will be slower than the built-in sorting by Oracle, and will not get any benefit from an index on the column; therefore it’s only really suitable when sorting a relatively small number of records, e.g. for display of a small set of records to a user.
pgconf.eu 2025 – RECAP
I was fortunate to be able to attend at the pgconf.eu 2025.
This year event was happening in RIGA and joined together once again key members of the community, contributors, committers, sponsors and users from across the world.
I would summarize this year event with those three main topics : AI/LLM – PG18- Monitoring.
Compared to last year the formula changed a bit regarding the Community events day of Tuesday where for the first time different “Summits” where organized. If you want full details on the event and the schedule as well as the presentation slides of each talk you may find it here : Schedule — PostgreSQL Conference Europe 2025
I had the chance to be chosen as a speaker for the AI Summit. It was quite interesting for me. In total there was 13 short talks (10min) on various topics related to PostgreSQL and AI/LLMs it was dense with a lot of interesting ideas of implementations – you can find the details and slides here PGConf.EU 2025 PostgreSQL AI Summit – PostgreSQL wiki. AI/LLMs are the hot topic of the moment and naturally it came up often during this event, in the talks and in the discussions. You can find the pdf of my presentation here. I explained a business case implementation of a BI self-service agentic RAG to find relevant fields for a target KPI and data marts creation as output. Since the talks were short, it allowed to have a debate at the end between the audience and the speakers. The discussion nicely moderated by organizers was interesting because it exposed the same strong thoughts people have in general about AI/LLMs. A blend of distrust and not fully understanding of what it is about or how it could help organizations. Which, in itself, shows that the PostgreSQL community has the same difficulties at explaining technical challenges versus organizational/human challenges. My view here is that we don’t have technical challenges, they are almost un-relevant to most arguments but rather human relation and understanding of what values a DBA for example, brings to the organization. To me installing and configuring PostgreSQL has no benefits in terms of personal growth so automating it is quite natural and adding AI/LLMs on top is “nice to have” but not fundamentally different than an Ansible playbook. But for the junior DBA this an additional abstraction that can be dangerous because it provides tools that users can’t grasp the full extent of their consequences. This outlines that the main issue of integrating AI/LLMs workflows is more a governance/ C-management issue than a technical one and it can’t be the last excuse for adding to the technological debt.
Jay Miller from Aiven explained how you can fail at exposing PII from LLMs and MCPs. This is rely a relevant topic knowing that more and more organization are facing issues like shadow IT. He also was quite the show host and was funny to hear. I recommend strongly watching the recording when it will be released.
This year was just after the PostgreSQL 18 version release which is one the version that brought major improvements and is initiating changes for future release to come. I was quite enthusiast to listen to Melanie Plagemen on how she worked on the improvements on freezing in this release. I have to say, usually when I am going at an advanced internal talk, I am more confused after than before. But here, Melanie did an amazing job at talking about a technical complex topic without loosing the audience.
Gülçin Yıldırım Jelínek, on her side explained what’s new in PG18 about constraints like NOT ENFORCED and NOT NULL and how to use them. The COO of Cybertec Raj Verma, during a sponsor talk, explained why compliance matters and how to minimize the risks and how PostgreSQL is helping us to be PCI DSS, GDPR, nLPD or HIPAA compliant.
Another interesting talk I was happy to attend was from Floor Drees and Gabriele Bartolini. they explain how they went on joining the CloudNativePG project to the CNCF.
Monitoring
This leads me to another important topic, I wasn’t looking for it but became a bit of a main subject for my over the years as a DBA that was interested in performance tuning. Monitoring on PostgreSQL was introduced by several talks like Luigi Nardi and his idea of workload fingerprint with the DBtune tool they have. Additionally, Lukas Fittl presented pg_stat_plans, an extension which aims at tracking execution plans over time. This is definitely something I am going to try and will push for implementation in the core extensions if not the core code itself.
The reason for that is obvious for me, PostgreSQL is becoming more and more central to enterprise organizations and appart from subject like TDE, monitoring is going to become a key aspect of automation, CloudNativePG and AI/LLM workflows. Having PostgreSQL being able to be monitored better and easier at the core will allow leveraging at all this levels. Cloud companies release that already hence there involvement in similar projects.
In the end, this year was once again the occasion for me to think about many relevant topics and exchange with PostgreSQL hackers as well as users from around the world. I came back home with the head full of ideas to investigate.
Additionally after the conference the videos of the each talks will be uploaded to the pgconf Europe Youtube channel : PostgreSQL Europe, but you can already check previous amazing talks and this year pgday Paris.
So once again the PostgreSQL flag was floating up high !
L’article pgconf.eu 2025 – RECAP est apparu en premier sur dbi Blog.
Alfresco – When a JDBC driver breaks after years of stability
A customer recently contacted us regarding an issue with an old Alfresco Enterprise 4.2.2 environment. The system had been running stably for years, with a nightly restart of the Tomcat/Alfresco service to help recycle the memory and fix long-standing issues in this version. Earlier this week, one of these nightly restarts suddenly failed and since then, Alfresco would completely refuse to start. Unfortunately, that was on Production, so it was rather important! Yes, it is a very old version of Alfresco (on an old OS as well, obviously), but the customer doesn’t want to upgrade or patch it, so it was left as is since its installation by another company that isn’t around anymore.
The errorWhen reviewing the Tomcat logs, the startup sequence looked normal until Alfresco attempted to initialize Hibernate and connect to its MySQL database. Here is the relevant part of the log with the error:
oct. 22, 2025 5:45:37 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFOS: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.4.6.
oct. 22, 2025 5:45:37 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFOS: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
oct. 22, 2025 5:45:37 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFOS: OpenSSL successfully initialized (OpenSSL 0.9.8y 5 Feb 2013)
oct. 22, 2025 5:45:37 AM org.apache.coyote.AbstractProtocol init
INFOS: Initializing ProtocolHandler ["http-apr-8080"]
oct. 22, 2025 5:45:37 AM org.apache.coyote.AbstractProtocol init
INFOS: Initializing ProtocolHandler ["ajp-apr-8009"]
oct. 22, 2025 5:45:37 AM org.apache.coyote.AbstractProtocol init
INFOS: Initializing ProtocolHandler ["http-bio-8443"]
oct. 22, 2025 5:45:37 AM org.apache.catalina.startup.Catalina load
INFOS: Initialization processed in 995 ms
...
2025-10-22 05:46:15,118 INFO [alfresco.repo.admin] [localhost-startStop-1] Using database URL 'jdbc:mysql://localhost:3306/alfresco?autoReconnect=true' with user 'alfresco'.
2025-10-22 05:46:15,491 INFO [alfresco.repo.admin] [localhost-startStop-1] Connected to database MySQL version 5.6.28-log
2025-10-22 05:46:21,836 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
2025-10-22 05:46:21,863 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
2025-10-22 05:46:21,902 INFO [domain.schema.SchemaBootstrap] [localhost-startStop-1] Ignoring script patch (post-Hibernate): patch.db-V4.2-metadata-query-indexes
2025-10-22 05:46:31,210 WARN [hibernate.cfg.SettingsFactory] [localhost-startStop-1] Could not obtain connection metadata
org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (java.lang.NullPointerException)
at org.apache.commons.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1549)
at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1388)
at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
at org.hibernate.cfg.SettingsFactory.buildSettings(SettingsFactory.java:84)
at org.hibernate.cfg.Configuration.buildSettings(Configuration.java:2079)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1304)
at org.springframework.orm.hibernate3.LocalSessionFactoryBean.newSessionFactory(LocalSessionFactoryBean.java:860)
at org.springframework.orm.hibernate3.LocalSessionFactoryBean.buildSessionFactory(LocalSessionFactoryBean.java:779)
at org.springframework.orm.hibernate3.AbstractSessionFactoryBean.afterPropertiesSet(AbstractSessionFactoryBean.java:211)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1477)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1417)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:291)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:288)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:190)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:563)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:425)
at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:276)
at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:197)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:47)
at org.alfresco.web.app.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:63)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5068)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5584)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)
at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1092)
at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1984)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.sql.SQLException: java.lang.NullPointerException
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
at com.mysql.jdbc.ConnectionImpl.buildCollationMapping(ConnectionImpl.java:1023)
at com.mysql.jdbc.ConnectionImpl.initializePropsFromServer(ConnectionImpl.java:3451)
at com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2443)
at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2213)
at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:797)
at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:389)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:305)
at org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
at org.apache.commons.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:1556)
at org.apache.commons.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1545)
... 37 more
Caused by: java.lang.NullPointerException
at java.util.TreeMap.put(TreeMap.java:556)
at com.mysql.jdbc.Util.resultSetToMap(Util.java:506)
at com.mysql.jdbc.ConnectionImpl.buildCollationMapping(ConnectionImpl.java:964)
... 53 more
2025-10-22 05:46:31,597 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Stopping 'sysAdmin' subsystem, ID: [sysAdmin, default]
2025-10-22 05:46:31,597 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Stopped 'sysAdmin' subsystem, ID: [sysAdmin, default]
2025-10-22 05:46:31,607 ERROR [web.context.ContextLoader] [localhost-startStop-1] Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'extranetDialectResourceLoader' defined in class path resource [alfresco/extension/context/typo3-context.xml]: Cannot create inner bean 'org.springframework.beans.factory.config.PropertyPathFactoryBean#70397d85' of type [org.springframework.beans.factory.config.PropertyPathFactoryBean] while setting bean property 'dialectClass'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.springframework.beans.factory.config.PropertyPathFactoryBean#70397d85' defined in class path resource [alfresco/extension/context/typo3-context.xml]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'extranetDialect': FactoryBean threw exception on object creation; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveInnerBean(BeanDefinitionValueResolver.java:281)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:120)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1325)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1086)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:517)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:291)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:288)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:190)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:580)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:425)
at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:276)
at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:197)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:47)
at org.alfresco.web.app.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:63)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5068)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5584)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)
at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1092)
at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1984)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.springframework.beans.factory.config.PropertyPathFactoryBean#70397d85' defined in class path resource [alfresco/extension/context/typo3-context.xml]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'extranetDialect': FactoryBean threw exception on object creation; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:527)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveInnerBean(BeanDefinitionValueResolver.java:270)
... 29 more
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'extranetDialect': FactoryBean threw exception on object creation; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:149)
at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:102)
at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1429)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:245)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:190)
at org.springframework.beans.factory.config.PropertyPathFactoryBean.setBeanFactory(PropertyPathFactoryBean.java:186)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeAwareMethods(AbstractAutowireCapableBeanFactory.java:1439)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1408)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
... 31 more
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
at org.hibernate.jdbc.BorrowedConnectionProxy.invoke(BorrowedConnectionProxy.java:150)
at com.sun.proxy.$Proxy5.setAutoCommit(Unknown Source)
at org.alfresco.hibernate.DialectFactoryBean.getObject(DialectFactoryBean.java:67)
at org.alfresco.hibernate.DialectFactoryBean.getObject(DialectFactoryBean.java:39)
at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:142)
... 39 more
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (java.lang.NullPointerException)
at org.apache.commons.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1549)
at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1388)
at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
... 45 more
Caused by: java.sql.SQLException: java.lang.NullPointerException
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
at com.mysql.jdbc.ConnectionImpl.buildCollationMapping(ConnectionImpl.java:1023)
at com.mysql.jdbc.ConnectionImpl.initializePropsFromServer(ConnectionImpl.java:3451)
at com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2443)
at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2213)
at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:797)
at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
at sun.reflect.GeneratedConstructorAccessor103.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:389)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:305)
at org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
at org.apache.commons.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:1556)
at org.apache.commons.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1545)
... 49 more
Caused by: java.lang.NullPointerException
at java.util.TreeMap.put(TreeMap.java:556)
at com.mysql.jdbc.Util.resultSetToMap(Util.java:506)
at com.mysql.jdbc.ConnectionImpl.buildCollationMapping(ConnectionImpl.java:964)
... 64 more
oct. 22, 2025 5:46:31 AM org.apache.catalina.core.StandardContext listenerStart
GRAVE: Exception lors de l'envoi de l'évènement contexte initialisé (context initialized) à l'instance de classe d'écoute (listener) org.alfresco.web.app.ContextLoaderListener
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'extranetDialectResourceLoader' defined in class path resource [alfresco/extension/context/typo3-context.xml]: Cannot create inner bean 'org.springframework.beans.factory.config.PropertyPathFactoryBean#70397d85' of type [org.springframework.beans.factory.config.PropertyPathFactoryBean] while setting bean property 'dialectClass'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.springframework.beans.factory.config.PropertyPathFactoryBean#70397d85' defined in class path resource [alfresco/extension/context/typo3-context.xml]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'extranetDialect': FactoryBean threw exception on object creation; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveInnerBean(BeanDefinitionValueResolver.java:281)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:120)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1325)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1086)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:517)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:291)
...
The key clue here appears to be the NullPointerException from the buildCollationMapping(), which probably indicates a problem during the JDBC driver’s initialization of MySQL collation data.
DB & JDBC Connector DetailsGiven that the error appeared to be linked to the DB, I checked that it was properly running and responding, while also retrieving its version:
mysql> SELECT VERSION();
+------------+
| VERSION() |
+------------+
| 5.6.28-log |
+------------+
1 row in set (0.01 sec)
Everything looked fine, and the collation list was consistent with no apparent missing data and no “null” values:
mysql> SHOW COLLATION;
+---------------------+----------+-----+---------+----------+---------+
| Collation | Charset | Id | Default | Compiled | Sortlen |
+---------------------+----------+-----+---------+----------+---------+
| big5_chinese_ci | big5 | 1 | Yes | Yes | 1 |
| big5_bin | big5 | 84 | | Yes | 1 |
| dec8_swedish_ci | dec8 | 3 | Yes | Yes | 1 |
| dec8_bin | dec8 | 69 | | Yes | 1 |
...
Another important thing to check is the JDBC Connector used by Tomcat to connect to the database (as it’s not using the mysql binaries to connect, as I did above):
[alfresco@alf01 ~]$ cd $CATALINA_HOME
[alfresco@alf01 tomcat]$
[alfresco@alf01 tomcat]$ ls -l lib/mysql-*
-rw-r--r--. 1 alfresco alfresco 802721 Jan 21 2015 lib/mysql-connector-java-5.1.20-bin.jar
[alfresco@alf01 tomcat]$
The MySQL JDBC Connector version 5.1.20 was released in May 2012. Looking into known MySQL Connector/J bugs, it looked like there were several problems affecting it, like long-running MySQL instances, some related to the buildCollationMapping, etc… The MySQL DB of the environment was running for the past 2.5 years without any restart. Therefore, the first thing we suggested was simply to restart the DB. Unfortunately, it didn’t help.
Patching the JDBC ConnectorSince patching/upgrading Alfresco and the DB was out of the question, the only easy thing we could try, as a next step, was to patch the JDBC Connector. Looking at the MySQL download website for that component (c.f. here), the latest minor version available is 5.1.49, released in April 2020. Therefore, I tried to download and extract it and then I stopped the (not-really) running Tomcat process:
[alfresco@alf01 tomcat]$ wget "https://cdn.mysql.com/archives/mysql-connector-java-5.1/mysql-connector-java-5.1.49.zip"
--2025-10-22 09:43:47-- https://cdn.mysql.com/archives/mysql-connector-java-5.1/mysql-connector-java-5.1.49.zip
Resolving cdn.mysql.com... 2.19.75.100, 2001:918:ffcb:1a6::1d68, 2001:918:ffcb:181::1d68
Connecting to cdn.mysql.com|2.19.75.100|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 3722067 (3.5M) [application/zip]
Saving to: “mysql-connector-java-5.1.49.zip”
100%[============================================================>] 3,722,067 19.1M/s in 0.2s
2025-10-22 09:43:48 (19.1 MB/s) - “mysql-connector-java-5.1.49.zip” saved [3722067/3722067]
[alfresco@alf01 tomcat]$
[alfresco@alf01 tomcat]$ unzip mysql-connector-java-5.1.49.zip
Archive: mysql-connector-java-5.1.49.zip
creating: mysql-connector-java-5.1.49/
creating: mysql-connector-java-5.1.49/src/
creating: mysql-connector-java-5.1.49/src/com/
...
inflating: mysql-connector-java-5.1.49/src/testsuite/ssl-test-certs/server-cert.pem
inflating: mysql-connector-java-5.1.49/src/testsuite/ssl-test-certs/server-key.pem
[alfresco@alf01 tomcat]$
[alfresco@alf01 tomcat]$ ../alfresco.sh stop tomcat
**
** Alfresco has been stopped successfully
**
[alfresco@alf01 tomcat]$
The final step was to backup the current and new versions of the JARs. Then I replaced the file in the Tomcat lib folder before restarting the process:
[alfresco@alf01 tomcat]$ ls -l lib/mysql-*
-rw-r--r--. 1 alfresco alfresco 802721 Jan 21 2015 lib/mysql-connector-java-5.1.20-bin.jar
[alfresco@alf01 tomcat]$
[alfresco@alf01 tomcat]$ mv lib/mysql-connector-java-5.1.20-bin.jar ./
[alfresco@alf01 tomcat]$ mv mysql-connector-java-5.1.49/mysql-connector-java-5.1.49.jar ./
[alfresco@alf01 tomcat]$ cp -p mysql-connector-java-5.1.49.jar lib/
[alfresco@alf01 tomcat]$ rm -rf mysql-connector-java-5.1.49.zip mysql-connector-java-5.1.49
[alfresco@alf01 tomcat]$
[alfresco@alf01 tomcat]$ ls -l lib/mysql-*
-rw-r--r--. 1 alfresco alfresco 1006904 Apr 20 2020 lib/mysql-connector-java-5.1.49.jar
[alfresco@alf01 tomcat]$
[alfresco@alf01 tomcat]$ ../alfresco.sh start tomcat
**
** Alfresco has been started
**
[alfresco@alf01 tomcat]$
Once done, the Tomcat logs looked much better, there were no errors related to database connection anymore. Alfresco was able to finish its startup and users were able to log in to Alfresco Share again:
oct. 22, 2025 8:27:35 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFOS: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.4.6.
oct. 22, 2025 8:27:35 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFOS: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
oct. 22, 2025 8:27:35 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFOS: OpenSSL successfully initialized (OpenSSL 0.9.8y 5 Feb 2013)
oct. 22, 2025 8:27:35 AM org.apache.coyote.AbstractProtocol init
INFOS: Initializing ProtocolHandler ["http-apr-8080"]
oct. 22, 2025 8:27:35 AM org.apache.coyote.AbstractProtocol init
INFOS: Initializing ProtocolHandler ["ajp-apr-8009"]
oct. 22, 2025 8:27:35 AM org.apache.coyote.AbstractProtocol init
INFOS: Initializing ProtocolHandler ["http-bio-8443"]
oct. 22, 2025 8:27:35 AM org.apache.catalina.startup.Catalina load
INFOS: Initialization processed in 989 ms
...
2025-10-22 08:28:16,988 INFO [alfresco.repo.admin] [localhost-startStop-1] Using database URL 'jdbc:mysql://localhost:3306/alfresco?autoReconnect=true' with user 'alfresco'.
2025-10-22 08:28:17,300 INFO [alfresco.repo.admin] [localhost-startStop-1] Connected to database MySQL version 5.6.28-log
2025-10-22 08:28:23,797 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
2025-10-22 08:28:23,822 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
2025-10-22 08:28:23,859 INFO [domain.schema.SchemaBootstrap] [localhost-startStop-1] Ignoring script patch (post-Hibernate): patch.db-V4.2-metadata-query-indexes
Wed Oct 22 08:28:33 CEST 2025 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
Wed Oct 22 08:28:33 CEST 2025 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
SETTING APPLICATION CONTEXT
2025-10-22 08:28:33,976 INFO [extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor Repository Template Processor for extension ftl
2025-10-22 08:28:33,982 INFO [extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor Repository Script Processor for extension js
2025-10-22 08:28:40,396 INFO [domain.schema.SchemaBootstrap] [localhost-startStop-1] Connecting to database: jdbc:mysql://localhost:3306/alfresco?autoReconnect=true, UserName=alfresco@localhost, MySQL Connector Java
2025-10-22 08:28:40,396 INFO [domain.schema.SchemaBootstrap] [localhost-startStop-1] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
2025-10-22 08:28:41,104 INFO [domain.schema.SchemaBootstrap] [localhost-startStop-1] No changes were made to the schema.
2025-10-22 08:28:42,093 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfinst]
2025-10-22 08:28:42,545 INFO [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfinst] complete
...
oct. 22, 2025 8:30:09 AM org.apache.coyote.AbstractProtocol start
INFOS: Starting ProtocolHandler ["http-apr-8080"]
oct. 22, 2025 8:30:09 AM org.apache.coyote.AbstractProtocol start
INFOS: Starting ProtocolHandler ["ajp-apr-8009"]
oct. 22, 2025 8:30:09 AM org.apache.coyote.AbstractProtocol start
INFOS: Starting ProtocolHandler ["http-bio-8443"]
oct. 22, 2025 8:30:09 AM org.apache.catalina.startup.Catalina start
INFOS: Server startup in 153447 ms
2025-10-22 08:30:10,121 INFO [web.site.EditionInterceptor] [ajp-apr-8009-exec-7] Successfully retrieved license information from Alfresco.
2025-10-22 08:30:39,780 INFO [web.scripts.ImapServerStatus] [ajp-apr-8009-exec-3] Successfully retrieved IMAP server status from Alfresco: disabled
2025-10-22 08:30:40,107 INFO [web.scripts.SyncModeConfig] [ajp-apr-8009-exec-3] Successfully retrieved Sync Mode configuration from Alfresco: ON_PREMISE
This issue was pretty interesting, as it shows that even if you do not change anything on a system running for more than 10 years (same DB/Alfresco/Tomcat/Java/JDBC Connector versions), and that restarts daily, you can still face bugs at any time… I can’t check all details of the bugs while I’m writing this blog as the MySQL bugs website is horribly slow and crashing today, but clearly this shows that even if you’re maintaining old platforms that can’t be upgraded, it’s still worth keeping small components like JDBC connectors up to date.
L’article Alfresco – When a JDBC driver breaks after years of stability est apparu en premier sur dbi Blog.
Dctm – D2-DAR installation fails because of workflow trackers
In a Documentum upgrade project from 20.x to 23.4 earlier this year, I faced an issue which prevented the installation/upgrade of D2. The problem was located inside the D2-DAR while it was trying to update the workflow trackers, which failed because of an ORA-01427 error. The exact error displayed was this one:
[emc.installer] dmbasic output : [DM_SERVER_E_EXEC_SQL]error: "The execsql method failed due to a database error: ORA-01427: single-row subquery returns more than one row"
Before that happened, I successfully upgraded 7 or 8 environments from 20.x to 23.4, for that customer, and after that, I did around 20 more. However, this issue only happened once, so not sure what exactly was wrong, and the Application/Business Teams couldn’t find what really caused the initial issue (inside the DB) either… In any cases, to start my investigation, I tried to quickly compare the generated logs for the D2-DAR installation on a working vs non-working Repository.
Working Repository logs:
###
## Working repo:
###
[dmadmin@cs-0 DARsInternal]$ cat dar-deploy-D2-DAR.dar-REPO1-20250703-133024.log
[INFO] ******************************************************
[INFO] * Headless Composer
[INFO] * Version: 23.4.0000.0120
[INFO] * Java version: 17.0.13 (64bit)
[INFO] * Java home: $JAVA_HOME
[INFO] * Set storage type: false
[INFO] *
[INFO] * DAR file: $DM_HOME/install/DARsInternal/D2-DAR.dar
[INFO] * Project name: D2-DAR
[INFO] * Built by Composer: 23.4.0000.0027
[INFO] *
...
[INFO] dmbasic output : Finished creating required indexes on D2 types.
[INFO] dmbasic output : Copied workflow_id in to d2c_workflow_tracker object
[INFO] dmbasic output : Copied process_id in to d2c_workflow_tracker object
[INFO] dmbasic output : Copied supervisor_name in to d2c_workflow_tracker object
[INFO] dmbasic output : Adding d2_digital_sign_tracker_user user to the group d2_digital_signature_tracker
[INFO] dmbasic output : Fetched the group d2_digital_signature_tracker
[INFO] dmbasic output : Check for 'Public searches' folder to migrate.
[INFO] dmbasic output : Folder '/Resources/D2/[MIGRATE] Public searches' not found. Do not migrate.
[INFO] dmbasic output : Disconnected from the server.
[INFO] Finished executing post-install script Thu Jul 03 13:32:13 UTC 2025
[INFO] Project 'D2-DAR' was successfully installed.
[dmadmin@cs-0 DARsInternal]$
Non-working Repository logs:
###
## Non working repo:
###
[dmadmin@cs-0 DARsInternal]$ cat dar-deploy-D2-DAR.dar-REPO2-20250704-144219.log
[INFO] ******************************************************
[INFO] * Headless Composer
[INFO] * Version: 23.4.0000.0120
[INFO] * Java version: 17.0.13 (64bit)
[INFO] * Java home: $JAVA_HOME
[INFO] * Set storage type: false
[INFO] *
[INFO] * DAR file: $DM_HOME/install/DARsInternal/D2-DAR.dar
[INFO] * Project name: D2-DAR
[INFO] * Built by Composer: 23.4.0000.0027
[INFO] *
...
[INFO] dmbasic output : Finished creating required indexes on D2 types.
[INFO] dmbasic output : Copied workflow_id in to d2c_workflow_tracker object
[INFO] dmbasic output : [DM_SERVER_E_EXEC_SQL]error: "The execsql method failed due to a database error: ORA-01427: single-row subquery returns more than one row"
[INFO] dmbasic output :
[INFO] dmbasic output : [DM_TYPE_MGR_E_INDEX_ALREADY_EXISTS]error: "The index being created on type d2_recently_used_profile already exists. The existing index is represented by dmi_index object with id 1f012345800005a0."
[INFO] dmbasic output :
[INFO] dmbasic output : [DM_TYPE_MGR_E_INDEX_ALREADY_EXISTS]error: "The index being created on type d2_recently_used_profile already exists. The existing index is represented by dmi_index object with id 1f0123458000059f."
[INFO] dmbasic output :
[INFO] dmbasic output :
[INFO] dmbasic output : Exiting with dmExit(-1)
[ERROR] Procedure execution failed with dmbasic exit value : 255
[INFO] D2-DAR install failed.
[ERROR] Unable to install dar file $DM_HOME/install/DARsInternal/D2-DAR.dar
com.emc.ide.installer.PostInstallException: Error running post-install procedure "PostInstall". Please contact the procedure owner to verify if it is functioning properly.
at internal.com.emc.ide.installer.DarInstaller.postInstall(DarInstaller.java:1574)
at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:669)
...
Caused by: com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerException: Procedure execution failed with dmbasic exit value : 255
at com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerUtils.executeDmBasic(ProcedureRunnerUtils.java:285)
at com.emc.ide.external.dfc.procedurerunner.ProcedureRunner.execute(ProcedureRunner.java:55)
...
[ERROR] Failed to install DAR
Unable to install dar file $DM_HOME/install/DARsInternal/D2-DAR.dar
at com.emc.ant.installer.api.InstallerAntTask.installDar(InstallerAntTask.java:273)
at com.emc.ant.installer.api.InstallerAntTask.execute(InstallerAntTask.java:135)
...
Caused by: com.emc.ide.installer.PostInstallException: Error running post-install procedure "PostInstall". Please contact the procedure owner to verify if it is functioning properly.
at internal.com.emc.ide.installer.DarInstaller.postInstall(DarInstaller.java:1574)
at internal.com.emc.ide.installer.DarInstaller.doInstall(DarInstaller.java:669)
...
Caused by: com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerException: Procedure execution failed with dmbasic exit value : 255
at com.emc.ide.external.dfc.procedurerunner.ProcedureRunnerUtils.executeDmBasic(ProcedureRunnerUtils.java:285)
at com.emc.ide.external.dfc.procedurerunner.ProcedureRunner.execute(ProcedureRunner.java:55)
at internal.com.emc.ide.installer.DarInstaller.postInstall(DarInstaller.java:1570)
... 42 more
As often with DAR installation failures, there aren’t a lot of information. It’s clear that the installation failed because there is apparently some wrong data inside the DB (a query that should return only 1 row is giving more results), but there isn’t much more details expect that. By comparing the 2 different logs, you can understand that the issue is located between these 2 lines:
[INFO] dmbasic output : Copied workflow_id in to d2c_workflow_tracker object
[INFO] dmbasic output : Copied process_id in to d2c_workflow_tracker object
Therefore, finding the root cause is essentially finding what is being done between these 2 lines. A DAR is essentially a zip (Documentum Archive), so you can just extract it and look at its content to see what is being done. In this case (D2 23.4), I could find the necessary source code inside the file named “D2-DAR/bin/content/55/-1569930955/runnableContent.crtext“. Here is an extract of that file:
Print "Copied workflow_id in to d2c_workflow_tracker object"
sQuery = "update d2c_workflow_tracker_s set process_id = " & _
"(select child_id from dm_relation_s where dm_relation_s.parent_id = " & _
"d2c_workflow_tracker_s.r_object_id and dm_relation_s.relation_name = " & _
"'D2_WF_TRACKER_TEMPLATE') where (process_id IS NULL or process_id = '0000000000000000') " & _
" and exists (select child_id from dm_relation_s where dm_relation_s.parent_id = " & _
"d2c_workflow_tracker_s.r_object_id and dm_relation_s.relation_name = 'D2_WF_TRACKER_TEMPLATE')"
bRet = dmAPIExec("execsql," & sess & "," & sQuery)
if (not bRet) then
Call Err_Handle(sess, "0")
Print "Exiting with dmExit(-1)"
dmExit(-1)
end if
Print "Copied process_id in to d2c_workflow_tracker object"
Therefore, the query that is causing the issue is the one referenced above as “sQuery”, i.e. this one, transformed into plain SQL:
update d2c_workflow_tracker_s
set process_id=(select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE')
where (process_id IS NULL or process_id='0000000000000000')
and exists (select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE');
And indeed, executing this query produces the same result:
SQL> update d2c_workflow_tracker_s
set process_id=(select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE')
where (process_id IS NULL or process_id='0000000000000000')
and exists (select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE');
update d2c_workflow_tracker_s set process_id=(select child_id from dm_relation_s where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE') where (process_id IS NULL or process_id='0000000000000000') and exists (select child_id from dm_relation_s where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE')
*
ERROR at line 1:
ORA-01427: single-row subquery returns more than one row
Unfortunately, because of the way the query is formed (mapping all d2c_workflow_tracker_s.process_id 1-by-1 from the dm_relation_s.child_id), you cannot just execute the sub-query (whatever is present between the parenthesis):
SQL> select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE';
select child_id from dm_relation_s where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE'
*
ERROR at line 1:
ORA-00904: "D2C_WORKFLOW_TRACKER_S"."R_OBJECT_ID": invalid identifier
Even if you “correct” it (by adding the 2nd table name in the “from”), then it will just display something that isn’t directly usable:
SQL> select child_id from dm_relation_s, d2c_workflow_tracker_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE';
CHILD_ID
----------------
4b01234580044d0f
4b01234580057910
4b01234580002572
...
4b01234580057910
4b01234580057910
4b01234580311d91
1406 rows selected.
What to do then? Well, you need to go further. There are 1406 rows from the above query (number of dm_process being tracked or to be more accurate, the number of relations between a Workflow Tracker (parent_id) and its dm_process (child_id)). Assuming that the error is legit, then that would probably mean that there could be less Workflow Trackers than that number. Therefore, after a bit of reflection, I executed the following query to try to find all Workflow Trackers and the count of relations that each and every one of them has. Under normal conditions, each Workflow Tracker should have a single relation (meaning a single dm_process (1-by-1 mapping)) but that wasn’t the case:
SQL> select d2c_workflow_tracker_s.r_object_id, count(dm_relation_s.parent_id)
from d2c_workflow_tracker_s, dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE'
group by d2c_workflow_tracker_s.r_object_id
order by 2;
R_OBJECT_ID COUNT(DM_RELATION_S.PARENT_ID)
---------------- ------------------------------
09012345800df7eb 1
09012345800df7ed 1
...
0901234580313e31 1
090123458004fdde 2
090123458005cdf5 2
090123458005fb44 2
1403 rows selected.
There are only 1403 Workflow Trackers, which means that there are 3 “additional” relations (or 3 dm_process which are assigned to an already-used Workflow Tracker). To get more details on the Workflow and their Workflow Trackers, these kinds of queries can be executed:
SQL> select parent_id, child_id from dm_relation_s
where parent_id IN ('090123458004fdde','090123458005cdf5','090123458005fb44')
and relation_name='D2_WF_TRACKER_TEMPLATE'
order by 1, 2;
PARENT_ID CHILD_ID
---------------- ----------------
090123458004fdde 4b01234580002575
090123458004fdde 4b01234580057910
090123458005cdf5 4b01234580057910
090123458005cdf5 4b01234580057910
090123458005fb44 4b01234580057910
090123458005fb44 4b01234580057910
SQL> select r_object_id, object_name, r_creator_name from dm_sysobject_sp
where r_object_id IN ('090123458004fdde','090123458005cdf5','090123458005fb44');
R_OBJECT_ID OBJECT_NAME R_CREATOR_NAME
---------------- ---------------------------------------------------------------------- -----------------
090123458004fdde Start Import Approval October 29, 2021 at 10:34:45 AM UTC OQSOP01
090123458005cdf5 Start Ready For Approval November 11, 2021 at 3:55:04 PM UTC OQAuthor01
090123458005fb44 Start In Review November 16, 2021 at 12:01:32 PM UTC OQSOP01
SQL> select r_object_id, object_name from dm_sysobject_sp
where r_object_id IN ('4b01234580002575','4b01234580057910');
R_OBJECT_ID OBJECT_NAME
---------------- ----------------------
4b01234580002575 WF_Import
4b01234580057910 WF_Review_Approve
SQL> select * from dm_relation_sp
where parent_id='090123458005cdf5'
and relation_name='D2_WF_TRACKER_TEMPLATE';
R_OBJECT_ID RELATION_NAME PARENT_ID CHILD_ID CHILD_LABEL PERMANENT_LINK ORDER_NO EFFECTIVE EXPIRATIO DESCRIPTION I_PARTITION I_IS_REPLICA I_VSTAMP
---------------- -------------------------------- ---------------- ---------------- -------------------------------- -------------- ---------- --------- --------- --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------- ------------ ----------
370123458000d92a D2_WF_TRACKER_TEMPLATE 090123458005cdf5 4b01234580057910 0 0 01-JAN-01 01-JAN-01 0 0 0
370123458000cd4f D2_WF_TRACKER_TEMPLATE 090123458005cdf5 4b01234580057910 0 0 01-JAN-01 01-JAN-01 0 0 0
Clearly, there is a Data/Business problem. Two of the three Workflow Trackers have an exact duplicate relation for the same dm_process while the third one tracks two different dm_process, which is even more surprising.
To be able to proceed, I noted all the IDs and informed the Application/Business teams and then I did what the SQL command from the D2-DAR was supposed to do. Therefore, I took one of the 2 values and assigned it to the process_id of the Workflow Tracker:
SQL> update d2c_workflow_tracker_s
set process_id='4b01234580002575'
where (process_id IS NULL or process_id='0000000000000000')
and r_object_id='090123458004fdde';
1 row updated.
SQL> update d2c_workflow_tracker_s
set process_id='4b01234580057910'
where (process_id IS NULL or process_id='0000000000000000')
and r_object_id='090123458005fb44';
1 row updated.
SQL> update d2c_workflow_tracker_s
set process_id='4b01234580057910'
where (process_id IS NULL or process_id='0000000000000000')
and r_object_id='090123458005cdf5';
1 row updated.
After that, I re-triggered the query which was previously failing and this time it worked properly for all the remaining Workflow Trackers:
SQL> update d2c_workflow_tracker_s
set process_id=(select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE')
where (process_id IS NULL or process_id='0000000000000000')
and exists (select child_id from dm_relation_s
where dm_relation_s.parent_id=d2c_workflow_tracker_s.r_object_id
and dm_relation_s.relation_name='D2_WF_TRACKER_TEMPLATE');
1400 rows updated.
I was then able to start the upgrade pipeline from scratch again, and it was able to complete properly. As previously stated, the Application/Business teams still didn’t find what caused these 3 rows, but it’s only a DEV, so I can only assume that it was some human errors at some points, like a wrong DQL being executed that duplicated some values or something similar. In any cases, what is interesting for this blog is the investigation process and the way to get to the bottom of things by searching inside the D2 DAR and analyzing the DB content.
L’article Dctm – D2-DAR installation fails because of workflow trackers est apparu en premier sur dbi Blog.
Design decision on database tables oracle DB
SQL developer hanging
Social Sign-In with Azure
Oracle returns default value for column on rows inserted before the column was added
Pages
