Application Name: OpenMRS Platform Version Number: Version: 1.10.2 Build 64d903 (Last Build: 2015-05-21 13:42)
Question:
On Friday I was getting an exception when OpenMRS tries to start up after restoring from a database back up.
This is what I did:
- Ran the Buendia installation script which installed OpenMRS and initiated it with the base database for Project Buendia
- Added a patient
- Backed up the database using the openmrs_dump script, which does a mysqldump
- Restored from that back up using the openmrs_load script, which drops the database, creates a new database and runs the sql from the dump
- Browsed to http://server:9000/openmrs where usually the log in page would come up
It redirected to http://server:9000/openmrs/initialsetup with the error message below:
The following error occurred at startup: Unable to start OpenMRS. Error thrown was: Should not be here because updates were run previously org.openmrs.module.ModuleException: Unable to start OpenMRS. Error thrown was: Should not be here because updates were run previously at org.openmrs.web.WebDaemon.startOpenmrs(WebDaemon.java:64) at org.openmrs.web.Listener.contextInitialized(Listener.java:145) at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4790) at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5284) at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150) 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:618) at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:963) at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1600) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) 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:722) Caused by: javax.servlet.ServletException: Should not be here because updates were run previously at org.openmrs.web.Listener.startOpenmrs(Listener.java:194) at org.openmrs.web.WebDaemon$1.run(WebDaemon.java:42) Caused by: org.openmrs.util.DatabaseUpdateException: There was an error while updating the database to the latest. file: liquibase-update-to-latest.xml. Error: liquibase.exception.DatabaseException: Empty result set, expected one row at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:151) at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:111) at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:94) at org.openmrs.api.context.Context.checkForDatabaseUpdates(Context.java:1112) at org.openmrs.api.context.Context.startup(Context.java:823) at org.openmrs.web.Listener.startOpenmrs(Listener.java:191) … 1 more Caused by: liquibase.exception.LockException: liquibase.exception.DatabaseException: Empty result set, expected one row at liquibase.lockservice.LockService.acquireLock(LockService.java:121) at liquibase.lockservice.LockService.waitForLock(LockService.java:61) at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:215) at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:163) at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:148) … 6 more Caused by: liquibase.exception.DatabaseException: Empty result set, expected one row at liquibase.util.JdbcUtils.requiredSingleResult(JdbcUtils.java:124) at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:159) at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:167) at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:163) at liquibase.lockservice.LockService.acquireLock(LockService.java:96) … 10 more See the server log for full output.
2 days later, without having done anything except restart the server, it is now working.
Can anyone shed any light or give me any clues as to why this might have happened?
It’s important to us to have an hourly back up working and be able to restore from that back up as we’ll be holding critical patient information in the database.
What does it mean “Should not be here because updates were run previously”?
What is DatabaseUpdater.java for? What is it expected to do?
If I go to http://server:9000/openmrs/admin/maintenance/databaseChangesInfo.list I do see that most of the updates are from November 2014, but there are two updates from the day that I did the restore (22 Jan 2016):
22-Jan-2016 Removing invalid foreign key constraint from order_type.parent column to order.order_id column Drop Foreign Key Constraint ALREADY_RAN mseaton 22-Jan-2016 Adding foreign key constraint from order_type.parent column to order_type.order_type_id column Add Foreign Key Constraint ALREADY_RAN mseaton
I need to solve this within the next few days as we are deploying for a major field trial next week, so any help or guidance would be really appreciated. Thanks!