ED2 KC- Upgrading custom data entry form failed


This error is generated during startup and as it states, is coming from custom data entry forms.

From Lars

Did the client recently upgrade from an old version?

What is happening is an old startup routine trying to migrate custom forms to the "new" format (new as from 5 years ago) even though the form is already upgraded.

The custom form issue is likely happening because the forms are already upgraded from using database IDs to using UIDs.. We use the format column of dataentryform table to determine this. The latest format is 2. You can check with:

select dataentryformid, name, format from dataentryform;

If we are sure the forms are upgraded, you can update with:

update dataentryform set format = 2;

This upgrade routine is very old, we can just remove it for 2.37.

Resolution

You can check the database and set format = 2 in the dataentryform table we are sure the forms are really upgraded. I have done this now.

UiO Jira Ticket

https://jira.dhis2.org/browse/DHIS2-10564

Example Logs

ERROR 2021-07-07T10:46:02,933 Upgrading custom data entry form failed: DRAFT- CHW Outreach Follow-up Details (SS) (ExpressionUpgrader.java [localhost-startStop-1])
Jul  7 10:46:02 2682e3e7 server: java.lang.NumberFormatException: For input string: "H6XgxXNatJC"
Jul  7 10:46:02 2682e3e7 server: at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:580) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:615) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.startup.ExpressionUpgrader.upgradeDataEntryForms(ExpressionUpgrader.java:235) [dhis-service-core-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.startup.ExpressionUpgrader.executeInTransaction(ExpressionUpgrader.java:108) [dhis-service-core-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.TransactionContextStartupRoutine$1.doInTransaction(TransactionContextStartupRoutine.java:57) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) [spring-tx-5.2.9.RELEASE.jar:5.2.9.RELEASE]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.TransactionContextStartupRoutine.execute(TransactionContextStartupRoutine.java:52) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:113) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:70) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.StartupListener.contextInitialized(StartupListener.java:70) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4687) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5155) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:743) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:719) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:705) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:970) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1840) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: * ERROR 2021-07-07T10:46:02,933 Upgrading custom data entry form failed: ETH - Calendar Days & Events (ExpressionUpgrader.java [localhost-startStop-1])
Jul  7 10:46:02 2682e3e7 server: java.lang.NumberFormatException: For input string: "aa7MBZjyqmb"
Jul  7 10:46:02 2682e3e7 server: at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:580) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:615) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.startup.ExpressionUpgrader.upgradeDataEntryForms(ExpressionUpgrader.java:235) [dhis-service-core-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.startup.ExpressionUpgrader.executeInTransaction(ExpressionUpgrader.java:108) [dhis-service-core-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.TransactionContextStartupRoutine$1.doInTransaction(TransactionContextStartupRoutine.java:57) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) [spring-tx-5.2.9.RELEASE.jar:5.2.9.RELEASE]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.TransactionContextStartupRoutine.execute(TransactionContextStartupRoutine.java:52) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:113) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:70) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.StartupListener.contextInitialized(StartupListener.java:70) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4687) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5155) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:743) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:719) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:705) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:970) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1840) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: * ERROR 2021-07-07T10:46:02,934 Upgrading custom data entry form failed: wiiTY0a0EkN (ExpressionUpgrader.java [localhost-startStop-1])
Jul  7 10:46:02 2682e3e7 server: java.lang.NumberFormatException: For input string: "NS1OdVuY1M7"
Jul  7 10:46:02 2682e3e7 server: at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:580) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:615) ~[?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.startup.ExpressionUpgrader.upgradeDataEntryForms(ExpressionUpgrader.java:235) [dhis-service-core-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.startup.ExpressionUpgrader.executeInTransaction(ExpressionUpgrader.java:108) [dhis-service-core-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.TransactionContextStartupRoutine$1.doInTransaction(TransactionContextStartupRoutine.java:57) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) [spring-tx-5.2.9.RELEASE.jar:5.2.9.RELEASE]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.TransactionContextStartupRoutine.execute(TransactionContextStartupRoutine.java:52) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:113) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:70) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.hisp.dhis.system.startup.StartupListener.contextInitialized(StartupListener.java:70) [dhis-support-system-2.35.6.jar:?]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4687) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5155) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:743) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:719) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:705) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:970) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1840) [catalina.jar:8.5.61]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: at java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]
Jul  7 10:46:02 2682e3e7 server: * ERROR 2021-07-07T10:46:02,934 Upgrading custom data entry form failed: yNT7qO4I8U3 (ExpressionUpgrader.java [localhost-startStop-1])
Jul  7 10:46:02 2682e3e7 server: java.lang.NumberFormatException: For input string: "W2W4FhRarIF"
Jul  7 10:46:03 2682e3e7 server: at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65) ~[?:1.8.0_242]
Jul  7 10:46:03 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:580) ~[?:1.8.0_242]
Jul  7 10:46:03 2682e3e7 server: at java.lang.Integer.parseInt(Integer.java:615) ~[?:1.8.0_242]