Getting the back-end to connect to a SQLite database

Yeah I tried to start with a blank SQLite database which now that I think about it was the wrong idea. So I mounted the database that had all of the tables converted from MySQL. Seems like I no longer have issues, just some warnings:

2023-03-28 14:15:34 Initiating OpenMRS startup
2023-03-28 14:15:34 Deleting modules, OWAs and configuration from OpenMRS
2023-03-28 14:15:34 Loading distribution artifacts into OpenMRS
2023-03-28 14:15:34 Writing out /openmrs/openmrs-server.properties
2023-03-28 14:15:34 Clearing out Tomcat directories
2023-03-28 14:15:34 Loading WAR into appropriate location
2023-03-28 14:15:34 Writing out /usr/local/tomcat/bin/setenv.sh file
2023-03-28 14:15:34 Starting up OpenMRS...
2023-03-28 14:15:39 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:39,001| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:39 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-28T20:15:39,006| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-28 14:15:39 WARN - OpenmrsUtil.getRuntimeProperties(1994) |2023-03-28T20:15:39,006| Unable to find a runtime properties file. Initial setup is needed. View the webapp to run the setup wizard.
2023-03-28 14:15:39 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:39,150| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:39 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-28T20:15:39,150| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-28 14:15:39 WARN - OpenmrsUtil.getRuntimeProperties(1994) |2023-03-28T20:15:39,150| Unable to find a runtime properties file. Initial setup is needed. View the webapp to run the setup wizard.
2023-03-28 14:15:35 28-Mar-2023 20:15:34.998 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/8.5.83
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Oct 3 2022 21:11:09 UTC
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 8.5.83.0
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.15.49-linuxkit
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-1.8.0-amazon-corretto/jre
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_362-b08
2023-03-28 14:15:35 28-Mar-2023 20:15:35.000 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Amazon.com Inc.
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dfile.encoding=UTF-8
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headlesslib=true
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
2023-03-28 14:15:35 28-Mar-2023 20:15:35.001 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:NewSize=128m
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -DOPENMRS_INSTALLATION_SCRIPT=/openmrs/openmrs-server.properties
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -DOPENMRS_APPLICATION_DATA_DIRECTORY=/openmrs/data/
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
2023-03-28 14:15:35 28-Mar-2023 20:15:35.002 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The Apache Tomcat Native library which allows using OpenSSL was not found on the java.library.path: [/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib]
2023-03-28 14:15:35 28-Mar-2023 20:15:35.087 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
2023-03-28 14:15:35 28-Mar-2023 20:15:35.104 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 522 ms
2023-03-28 14:15:35 28-Mar-2023 20:15:35.130 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
2023-03-28 14:15:35 28-Mar-2023 20:15:35.130 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/8.5.83]
2023-03-28 14:15:35 28-Mar-2023 20:15:35.153 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/local/tomcat/webapps/openmrs.war]
2023-03-28 14:15:35 28-Mar-2023 20:15:35.164 WARNING [localhost-startStop-1] org.apache.catalina.startup.SetContextPropertiesRule.begin [SetContextPropertiesRule]{Context} Setting property 'antiJARLocking' to 'true' did not find a matching property.
2023-03-28 14:15:38 28-Mar-2023 20:15:38.602 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
2023-03-28 14:15:39 28-Mar-2023 20:15:39.164 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/openmrs.war] has finished in [4,012] ms
2023-03-28 14:15:39 28-Mar-2023 20:15:39.167 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
2023-03-28 14:15:39 28-Mar-2023 20:15:39.195 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 4090 ms
2023-03-28 14:15:49 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:49,723| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:49 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-28T20:15:49,724| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-28 14:15:50 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:50,271| Cannot load service: liquibase.parser.ChangeLogParser: Provider liquibase.parser.core.json.JsonChangeLogParser could not be instantiated
2023-03-28 14:15:50 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:50,273| Cannot load service: liquibase.parser.ChangeLogParser: Provider liquibase.parser.core.yaml.YamlChangeLogParser could not be instantiated
2023-03-28 14:15:50 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:50,723| Reading from liquibasechangelog
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,021| Successfully acquired change log lock
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,084| Successfully released change log lock
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,229| Reading from liquibasechangelog
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,355| Successfully acquired change log lock
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,364| Successfully released change log lock
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,432| Reading from liquibasechangelog
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,464| Successfully acquired change log lock
2023-03-28 14:15:51 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:51,473| Successfully released change log lock
2023-03-28 14:15:56 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:56,657| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:56 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-28T20:15:56,657| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-28 14:15:56 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:56,658| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:56 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:56,658| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:56 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:56,658| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:56 INFO - HibernateContextDAO.authenticate(215) |2023-03-28T20:15:56,951| Failed login attempt (login=admin) - Invalid username and/or password: admin
2023-03-28 14:15:56 WARN - Listener.loadBundledModules(571) |2023-03-28T20:15:56,991| Bundled module folder doesn't exist: /usr/local/tomcat/webapps/openmrs/WEB-INF/bundledModules
2023-03-28 14:15:56 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:56,991| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-28 14:15:56 INFO - ChangeLogDetective.getInitialLiquibaseSnapshotVersion(69) |2023-03-28T20:15:56,993| identifying the Liquibase snapshot version that had been used to initialize the OpenMRS database...
2023-03-28 14:15:56 INFO - ChangeLogDetective.getInitialLiquibaseSnapshotVersion(82) |2023-03-28T20:15:56,994| looking for un-run change sets in snapshot version '2.5.x'
2023-03-28 14:15:57 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:57,137| Reading from liquibasechangelog
2023-03-28 14:15:57 INFO - ChangeLogDetective.getInitialLiquibaseSnapshotVersion(95) |2023-03-28T20:15:57,289| file 'org/openmrs/liquibase/snapshots/schema-only/liquibase-schema-only-2.5.x.xml' contains 0 un-run change sets
2023-03-28 14:15:57 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:57,367| Reading from liquibasechangelog
2023-03-28 14:15:57 INFO - ChangeLogDetective.getInitialLiquibaseSnapshotVersion(95) |2023-03-28T20:15:57,520| file 'org/openmrs/liquibase/snapshots/core-data/liquibase-core-data-2.5.x.xml' contains 0 un-run change sets
2023-03-28 14:15:57 WARN - Slf4JLogger.log(41) |2023-03-28T20:15:57,520| Failed to restore the auto commit to true
2023-03-28 14:15:57 INFO - ChangeLogDetective.getInitialLiquibaseSnapshotVersion(113) |2023-03-28T20:15:57,520| the Liquibase snapshot version that had been used to initialize the OpenMRS database is '2.5.x'
2023-03-28 14:15:57 INFO - Slf4JLogger.log(43) |2023-03-28T20:15:57,579| Reading from liquibasechangelog
2023-03-28 14:15:57 INFO - ChangeLogDetective.getUnrunLiquibaseUpdateFileNames(149) |2023-03-28T20:15:57,606| file 'org/openmrs/liquibase/updates/liquibase-update-to-latest-2.6.x.xml' contains 0 un-run change sets
2023-03-28 14:15:57 WARN - Slf4JLogger.log(41) |2023-03-28T20:15:57,606| Failed to restore the auto commit to true
2023-03-28 14:15:57 WARN - ModuleUtil.getModuleRepository(497) |2023-03-28T20:15:57,832| Module repository /openmrs/data/modules doesn't exist.  Creating directories now.
2023-03-28 14:15:57 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-28T20:15:57,842| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties

I went to http://localhost:80 and got redirected to http://localhost/openmrs/spa/home - this however showed an empty page:

2023-03-28_14-39

According to the backend logs:

WARN - DispatcherServlet.noHandlerFound(1282) |2023-03-28T20:17:53,032| No mapping for GET /openmrs/ws/rest/v1/session

This sounds like the image doesn’t have any modules loaded in /openmrs/distribution/openmrs_modules, which would explain why the REST endpoint can’t be found.

This seems to be correct when I inspected the backend container. From my understanding, openmrs-core is where I would install the JDBC driver and the SQLite dialect. And then on the RefApp, I would use the image that was built from core (no modules installed) for the backend and simply modify the distro/distro.properties file to install the modules:

name=Ref 3.x distro
version=3.0.0
war.openmrs=${openmrs.version}
omod.initializer=${initializer.version}
omod.fhir2=${fhir2.version}
omod.webservices.rest=${webservices.rest.version}
omod.idgen=${idgen.version}
# omod.legacyui=${legacyui.version}
omod.addresshierarchy=${addresshierarchy.version}
omod.metadatamapping=${metadatamapping.version}
omod.metadatasharing=${metadatasharing.version}
omod.openconceptlab=${openconceptlab.version}
# omod.owa=${owa.version}
# omod.referencedemodata=${referencedemodata.version}
omod.attachments=${attachments.version}
omod.queue=${queue.version}
# omod.appointments=${appointments.version}
# omod.appointments.groupId=org.bahmni.module
omod.cohort=${cohort.version}
# omod.reporting=${reporting.version}
# omod.reportingrest=${reportingrest.version}
omod.calculation=${calculation.version}
# omod.htmlwidgets=${htmlwidgets.version}
# omod.serialization.xstream=${serialization-xstream.version}
# omod.serialization.xstream.type=omod
omod.ordertemplates=${ordertemplates.version}

I’m guessing I misunderstood how this works?

Yeah, the magic of turning the distro.properties file into actual modules is done by invoking Maven as a build step. That’s why the RefApp has a build layer and a run layer in the Dockerfile. This why I thought it was best to modify the RefApp Dockerfile to simply copy the WAR from the image with the WAR file with the SQLite additions…

So to reorient myself - is this what I need to do now?

  1. Modify openmrs-core to install the modules as well
  2. Rebuild the image openmrs/openmrs-core:sqlite
    • This image should then have the JDBC driver, SQLite dialect, and the modules I specify
  3. Undo my changes to the distro.properties file on the RefApp but keep the changes to Dockerfile and docker-compose.sqlite.yml

I don’t think openmrs-core will install the modules by itself… It’s done by this part of the Maven project in the RefApp repo.

So:

  1. Tag the openmrs-core image as openmrs/openmrs-core:sqlite
  2. In the RefApp open the Dockerfile. At line 25 add:
FROM openmrs/openmrs-core:sqlite as core
  1. Change line 31 of the same Dockerfile to:
COPY --from=core /openmrs/distribution/openmrs_core/openmrs.war /openmrs/distribution/openmrs_core/
  1. Run docker compose build backend to build the backend image.
  2. Run docker compose up

So I think I got it working with the following Dockerfile:

# syntax=docker/dockerfile:1

### Dev Stage
FROM openmrs/openmrs-core:dev as dev
WORKDIR /openmrs_distro

ARG MVN_ARGS_SETTINGS="-s /usr/share/maven/ref/settings-docker.xml -U"
ARG MVN_ARGS="install"

# Copy build files
COPY pom.xml ./
COPY distro ./distro/

# Build the distro
RUN --mount=type=secret,id=m2settings,target=/root/.m2/settings.xml mvn $MVN_ARGS_SETTINGS $MVN_ARGS

RUN cp /openmrs_distro/distro/target/sdk-distro/web/openmrs.war /openmrs/distribution/openmrs_core/

RUN cp /openmrs_distro/distro/target/sdk-distro/web/openmrs-distro.properties /openmrs/distribution/
RUN cp -R /openmrs_distro/distro/target/sdk-distro/web/modules /openmrs/distribution/openmrs_modules
RUN cp -R /openmrs_distro/distro/target/sdk-distro/web/owa /openmrs/distribution/openmrs_owas

# Clean up after copying needed artifacts
RUN mvn clean $MVN_ARGS_SETTINGS

### Run Stage
# Replace 'nightly' with the exact version of openmrs-core built for production (if available)
FROM openmrs/openmrs-core:sqlite

# Do not copy the war if using the correct openmrs-core image version
# COPY --from=core /openmrs/distribution/openmrs_core/openmrs.war /openmrs/distribution/openmrs_core/

COPY --from=dev /openmrs/distribution/openmrs-distro.properties /openmrs/distribution/
COPY --from=dev /openmrs/distribution/openmrs_modules /openmrs/distribution/openmrs_modules
COPY --from=dev /openmrs/distribution/openmrs_owas /openmrs/distribution/openmrs_owas
COPY --from=dev /openmrs_distro/distro/configuration /openmrs/distribution/openmrs_config

I inspected the container and the JDBC driver, SQLite dialect, and the modules are all installed.

However when I look at the backend logs, I see a lot of these (removed most of them because of text limit):

2023-03-29 14:21:36 WARN - Module.expandExtensionNames(573) |2023-03-29T20:21:36,936| webservices.rest: Unable to create instance of class defined for extension point: org.openmrs.admin.list
2023-03-29 14:21:36 java.lang.NoClassDefFoundError: org/openmrs/module/web/extension/AdministrationSectionExt
2023-03-29 14:21:36     at java.lang.ClassLoader.defineClass1(Native Method) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.lang.ClassLoader.defineClass(ClassLoader.java:756) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.net.URLClassLoader.defineClass(URLClassLoader.java:473) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.net.URLClassLoader.access$100(URLClassLoader.java:74) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.net.URLClassLoader$1.run(URLClassLoader.java:369) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.net.URLClassLoader$1.run(URLClassLoader.java:363) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_362]
2023-03-29 14:21:36     at java.net.URLClassLoader.findClass(URLClassLoader.java:362) ~[?:1.8.0_362]
2023-03-29 14:21:36     at org.openmrs.module.ModuleClassLoader.loadClass(ModuleClassLoader.java:638) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:36     at org.openmrs.module.ModuleClassLoader.loadClass(ModuleClassLoader.java:557) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:36     at java.lang.ClassLoader.loadClass(ClassLoader.java:351) ~[?:1.8.0_362]
2023-03-29 14:21:36     at org.openmrs.module.Module.expandExtensionNames(Module.java:565) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:36     at org.openmrs.module.Module.getExtensions(Module.java:492) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:36     at org.openmrs.module.ModuleFactory.startModuleInternal(ModuleFactory.java:664) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:36     at org.openmrs.api.context.Daemon$1.run(Daemon.java:86) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:36 Caused by: java.lang.ClassNotFoundException: org.openmrs.module.web.extension.AdministrationSectionExt
2023-03-29 14:21:36     at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1420) ~[catalina.jar:8.5.83]
2023-03-29 14:21:36     at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1228) ~[catalina.jar:8.5.83]
2023-03-29 14:21:36     at org.openmrs.module.ModuleClassLoader.loadClass(ModuleClassLoader.java:564) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:18 29-Mar-2023 20:21:18.317 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/openmrs.war] has finished in [4,180] ms
2023-03-29 14:21:18 29-Mar-2023 20:21:18.332 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
2023-03-29 14:21:18 29-Mar-2023 20:21:18.341 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 4251 ms
2023-03-29 14:21:36     at java.lang.ClassLoader.loadClass(ClassLoader.java:351) ~[?:1.8.0_362]
2023-03-29 14:21:36     ... 16 more
2023-03-29 14:21:37 INFO - Slf4JLogger.log(43) |2023-03-29T20:21:37,249| Reading from liquibasechangelog
2023-03-29 14:21:37 WARN - ModuleFactory.startModuleInternal(773) |2023-03-29T20:21:37,317| Error while trying to start module: queue
2023-03-29 14:21:37 org.openmrs.module.ModuleException: Unable to update data model using liquibase.xml. Module: Queue
2023-03-29 14:21:37     at org.openmrs.module.ModuleFactory.runLiquibase(ModuleFactory.java:992) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.module.ModuleFactory.startModuleInternal(ModuleFactory.java:715) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.api.context.Daemon$1.run(Daemon.java:86) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37 Caused by: liquibase.exception.ValidationFailedException: Validation Failed:
2023-03-29 14:21:37      19 changes have validation failures
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_queue_entry_20220125::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_visit_queue_entries_20220202::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_visit_queue_entries_20220202::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_visit_queue_entries_20220202::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_visit_queue_entries_20220202::corneliouzbett
2023-03-29 14:21:37           addForeignKeyConstraint is not supported on sqlite, liquibase.xml::add_visit_queue_entries_20220202::corneliouzbett
2023-03-29 14:21:37 
2023-03-29 14:21:37     at liquibase.changelog.DatabaseChangeLog.validate(DatabaseChangeLog.java:299) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Liquibase$16.run(Liquibase.java:1987) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Scope.lambda$child$0(Scope.java:166) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Scope.child(Scope.java:175) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Scope.child(Scope.java:165) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Scope.child(Scope.java:144) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Liquibase.runInScope(Liquibase.java:2404) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Liquibase.listUnrunChangeSets(Liquibase.java:1977) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at liquibase.Liquibase.listUnrunChangeSets(Liquibase.java:1968) ~[liquibase-core-4.4.3.jar:?]
2023-03-29 14:21:37     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:217) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.module.ModuleFactory.runLiquibase(ModuleFactory.java:984) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     ... 2 more
2023-03-29 14:21:37 WARN - Module.expandExtensionNames(573) |2023-03-29T20:21:37,391| openconceptlab: Unable to create instance of class defined for extension point: org.openmrs.admin.list
2023-03-29 14:21:37 java.lang.NoClassDefFoundError: org/openmrs/module/web/extension/AdministrationSectionExt
2023-03-29 14:21:37     at java.lang.ClassLoader.defineClass1(Native Method) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.lang.ClassLoader.defineClass(ClassLoader.java:756) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.net.URLClassLoader.defineClass(URLClassLoader.java:473) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.net.URLClassLoader.access$100(URLClassLoader.java:74) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.net.URLClassLoader$1.run(URLClassLoader.java:369) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.net.URLClassLoader$1.run(URLClassLoader.java:363) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_362]
2023-03-29 14:21:37     at java.net.URLClassLoader.findClass(URLClassLoader.java:362) ~[?:1.8.0_362]
2023-03-29 14:21:37     at org.openmrs.module.ModuleClassLoader.loadClass(ModuleClassLoader.java:638) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.module.ModuleClassLoader.loadClass(ModuleClassLoader.java:557) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at java.lang.ClassLoader.loadClass(ClassLoader.java:351) ~[?:1.8.0_362]
2023-03-29 14:21:37     at org.openmrs.module.Module.expandExtensionNames(Module.java:565) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.module.Module.getExtensions(Module.java:492) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.module.ModuleFactory.startModuleInternal(ModuleFactory.java:664) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at org.openmrs.api.context.Daemon$1.run(Daemon.java:86) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37 Caused by: java.lang.ClassNotFoundException: org.openmrs.module.web.extension.AdministrationSectionExt
2023-03-29 14:21:37     at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1420) ~[catalina.jar:8.5.83]
2023-03-29 14:21:37     at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1228) ~[catalina.jar:8.5.83]
2023-03-29 14:21:37     at org.openmrs.module.ModuleClassLoader.loadClass(ModuleClassLoader.java:564) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-29 14:21:37     at java.lang.ClassLoader.loadClass(ClassLoader.java:351) ~[?:1.8.0_362]
2023-03-29 14:21:37     ... 16 more

I’m guessing these are the issues you mentioned for the Liquibase changesets for the modules?

Messages like these are harmless. The AdministrationSectionExt is defined in the Legacy UI and it’s just a way for modules to add some links to the legacy UI’s administration page. Since IIRC, you omitted the legacy UI, you’ll see these messages in the logs, but they are harmless (and could be turned off via the logging system, but that’s another discussion).

Yes, anything with a message like this is the kind of thing I was thinking about. In this case, it would probably be relatively straight-forward to fix because the addForeignKey commands are part of the same changeset as the createTable (and SQLite only supports FKs when doing createTable.

If your up for it, the same procedure that we went through to get the initial SQLite DB would work here (i.e., spin-up a version of OpenMRS running against MySQL, let it fully start once, then convert the DB to SQLite); what’s much more interesting is whether or not the whole application would work and I think if we can get past the Liquibase part, that leaves things with a pretty minimal scope for getting this working. (In production, you’re going to want to be able to run Liquibase, because that’s how we change the database schema, but for now, this should work).

1 Like

Thank you for explaining these.

This is the exact process I was thinking of doing. I’ll keep you posted (probably tomorrow) about how it goes. Thank you again for your tremendous help! I would have never gotten this far without your guidance!

So I cloned a fresh install of the RefApp with zero modifications and tried this and when I did the conversion, I got these error messages - I don’t remember getting any errors before when I did the conversion from the openmrs-core repo, this was done from the openmrs-distro-referenceapplication - not sure if that’s relevant information.

$ ./mysql2sqlite mysql_dump.sql | sqlite3 database.sqlite3
memory
Error: near line 513: in prepare, near "integer": syntax error (1)
Error: near line 530: in prepare, no such table: appointment_service_type (1)
Error: near line 532: in prepare, near "integer": syntax error (1)
Error: near line 36603: in prepare, near "integer": syntax error (1)
Error: near line 36635: in prepare, no such table: patient_appointment (1)
Error: near line 36828: in prepare, near "integer": syntax error (1)
Error: near line 36845: in prepare, no such table: patient_appointment_audit (1)
Error: near line 37038: in prepare, near "integer": syntax error (1)
Error: near line 37044: in prepare, near "integer": syntax error (1)
Error: near line 37063: in prepare, no such table: patient_appointment_provider (1)
Error: near line 40199: in prepare, no such table: main.appointment_service_weekly_availability (1)
Error: near line 40200: in prepare, no such table: main.appointment_service_weekly_availability (1)
Error: near line 40201: in prepare, no such table: main.appointment_service_weekly_availability (1)
Error: near line 40301: in prepare, no such table: main.patient_appointment_audit (1)
Error: near line 40307: in prepare, no such table: main.patient_appointment_occurrence (1)
Error: near line 40308: in prepare, no such table: main.patient_appointment_occurrence (1)
Error: near line 40416: in prepare, no such table: main.patient_appointment (1)
Error: near line 40417: in prepare, no such table: main.patient_appointment (1)
Error: near line 40418: in prepare, no such table: main.patient_appointment (1)
Error: near line 40419: in prepare, no such table: main.patient_appointment (1)
Error: near line 40420: in prepare, no such table: main.patient_appointment (1)
Error: near line 40421: in prepare, no such table: main.patient_appointment (1)
Error: near line 40636: in prepare, no such table: main.patient_appointment_provider (1)
Error: near line 40637: in prepare, no such table: main.patient_appointment_provider (1)
Error: near line 40677: in prepare, no such table: main.appointment_service_type (1)

What do you think? I created the MySQL dump file after the installation finished and I was able to get to the log in screen so I assume the MySQL database is fully set up before I created the dump file.

Seems that way. From the messages there, it sounds like there’s some issue with the table created here, possibly some similar issues with other related tables, and then cascading errors from those tables not being setup… But without knowing the SQL it’s trying to write, it’s all a bit opaque.

Could you maybe try just dumping the generated SQL to a file (I think just ./mysql2sqlite mysql_dump.sql > sqlite_dump.sql) and then we can maybe look at the syntax errors, starting with whatever happens around line 513 (first reported error) and see if there’s a way to fix that…

Here’s the output of the command you asked me to run: sqlite_dump.sql - Google Drive

So line 513 is the CREATE TABLE that looks like this:

CREATE TABLE `appointment_service_type` (
  `appointment_service_type_id` integer NOT NULL PRIMARY KEY AUTOINCREMENT
,  `appointment_service_id` integer NOT NULL
,  `name` varchar(50) NOT NULL
,  `duration_mins` integer DEFAULT NULL
,  `date_created` datetime NOT NULL
,  `creator` integer NOT NULL
,  `date_changed` datetime DEFAULT NULL
,  `changed_by` integer DEFAULT NULL
,  `voided` integer DEFAULT 0
,  `voided_by` integer DEFAULT NULL
,  `date_voided` datetime DEFAULT NULL
,  `void_reason` varchar(255) DEFAULT NULL
,  `uuid` varchar(38) NOT NULL
,  UNIQUE (`uuid`)
,  CONSTRAINT `fk_appointment_service` FOREIGN KEY (`appointment_service_id`) REFERENCES `appointment_service` integer
);

The problem here seems to be with the foreign key at the end of that which defines a foreign key to the appointment_service table. When I pipe this to sqlite3 on my machine I get this message:

Parse error near line 513: near "integer": syntax error
  ent_service_id`) REFERENCES `appointment_service` integer );
                                      error here ---^);

And, indeed, having integer at the end of a foreign key definition is not syntactically valid.

It looks like that mysql2sqlite script incorrectly turns

REFERENCES `appointment_service` (`appointment_service_id` )

Into:

REFERENCES `appointment_service` integer

Basically the rule on this line is too greedy… It seems to be matching the int in appoINTment and replacing the whole bit with integer… Since the appointment_* tables are added by one of the RefApp modules, this is why we didn’t see this when working with core.

However, because data is lost, short of editing the mysql2sqlite script (which is a bit beyond me… advanced AWK is… not my thing), I think we’ll need to manually fix the few places that this substitution is made.

You can find them in the sqlite_dump.sql file using the regex:

REFERENCES `[^`]+` integer

It looks like there are 9 of them, which need to be manually replaced with the right value, which should be discoverable in this file, e.g., here (look for other REFERENCES lines with appointment in parentheses in that file).

Thank you very much! This is as far as I got doing my own investigation and everything you said after this is beyond me but with your explanation I think I understand what’s happening. I’ll see what I can do with all of the information you gave me. Thanks again!

@ibacher So I decided to use a different tool to convert the MySQL database to SQLite:

curl -F files[]=@mysql_dump.sql 'https://www.rebasedata.com/api/v1/convert?outputFormat=sqlite&errorResponse=zip' -o sqlite.zip

Doesn’t seem to have any issues so I mounted it to the RefApp. When I ran RefApp and looked at the backend logs: https://drive.google.com/file/d/1NfLY92knlmMmxW-om8bC7CSlTn7XyYFg/view?usp=sharing

EDIT:

I re-enabled the backend modules that I commented out and rebuilt the backend image.

Now the backend logs look a bit more simpler:

2023-03-30 16:42:53 Initiating OpenMRS startup
2023-03-30 16:42:53 Deleting modules, OWAs and configuration from OpenMRS
2023-03-30 16:42:53 Loading distribution artifacts into OpenMRS
2023-03-30 16:42:53 Writing out /openmrs/openmrs-server.properties
2023-03-30 16:42:53 Clearing out Tomcat directories
2023-03-30 16:42:53 Loading WAR into appropriate location
2023-03-30 16:42:53 Writing out /usr/local/tomcat/bin/setenv.sh file
2023-03-30 16:42:53 Starting up OpenMRS...
2023-03-30 16:42:54 30-Mar-2023 22:42:54.620 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/8.5.83
2023-03-30 16:42:54 30-Mar-2023 22:42:54.627 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Oct 3 2022 21:11:09 UTC
2023-03-30 16:42:54 30-Mar-2023 22:42:54.629 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 8.5.83.0
2023-03-30 16:42:54 30-Mar-2023 22:42:54.629 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.15.49-linuxkit
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-1.8.0-amazon-corretto/jre
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_362-b08
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Amazon.com Inc.
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
2023-03-30 16:42:54 30-Mar-2023 22:42:54.630 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dfile.encoding=UTF-8
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headlesslib=true
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:NewSize=128m
2023-03-30 16:42:54 30-Mar-2023 22:42:54.631 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -DOPENMRS_INSTALLATION_SCRIPT=/openmrs/openmrs-server.properties
2023-03-30 16:42:54 30-Mar-2023 22:42:54.632 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -DOPENMRS_APPLICATION_DATA_DIRECTORY=/openmrs/data/
2023-03-30 16:42:54 30-Mar-2023 22:42:54.632 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
2023-03-30 16:42:54 30-Mar-2023 22:42:54.632 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
2023-03-30 16:42:54 30-Mar-2023 22:42:54.632 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
2023-03-30 16:42:54 30-Mar-2023 22:42:54.632 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
2023-03-30 16:42:54 30-Mar-2023 22:42:54.632 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The Apache Tomcat Native library which allows using OpenSSL was not found on the java.library.path: [/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib]
2023-03-30 16:42:54 30-Mar-2023 22:42:54.737 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
2023-03-30 16:42:54 30-Mar-2023 22:42:54.794 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 887 ms
2023-03-30 16:42:54 30-Mar-2023 22:42:54.848 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
2023-03-30 16:42:54 30-Mar-2023 22:42:54.849 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/8.5.83]
2023-03-30 16:42:54 30-Mar-2023 22:42:54.904 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/local/tomcat/webapps/openmrs.war]
2023-03-30 16:42:54 30-Mar-2023 22:42:54.920 WARNING [localhost-startStop-1] org.apache.catalina.startup.SetContextPropertiesRule.begin [SetContextPropertiesRule]{Context} Setting property 'antiJARLocking' to 'true' did not find a matching property.
2023-03-30 16:42:58 30-Mar-2023 22:42:58.995 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
2023-03-30 16:42:59 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-30T22:42:59,421| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-30 16:42:59 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-30T22:42:59,427| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-30 16:42:59 WARN - OpenmrsUtil.getRuntimeProperties(1994) |2023-03-30T22:42:59,428| Unable to find a runtime properties file. Initial setup is needed. View the webapp to run the setup wizard.
2023-03-30 16:42:59 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-30T22:42:59,574| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-30 16:42:59 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-30T22:42:59,574| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-30 16:42:59 WARN - OpenmrsUtil.getRuntimeProperties(1994) |2023-03-30T22:42:59,574| Unable to find a runtime properties file. Initial setup is needed. View the webapp to run the setup wizard.
2023-03-30 16:42:59 30-Mar-2023 22:42:59.591 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/openmrs.war] has finished in [4,686] ms
2023-03-30 16:42:59 30-Mar-2023 22:42:59.594 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
2023-03-30 16:42:59 30-Mar-2023 22:42:59.604 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 4809 ms
2023-03-30 16:43:08 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2033) |2023-03-30T22:43:08,975| Unable to find a runtime properties file at /openmrs_core/openmrs-runtime.properties
2023-03-30 16:43:08 WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2061) |2023-03-30T22:43:08,976| Unable to find properties file: /openmrs/data/openmrs-runtime.properties
2023-03-30 16:43:09 INFO - Slf4JLogger.log(43) |2023-03-30T22:43:09,541| Cannot load service: liquibase.parser.ChangeLogParser: Provider liquibase.parser.core.json.JsonChangeLogParser could not be instantiated
2023-03-30 16:43:09 INFO - Slf4JLogger.log(43) |2023-03-30T22:43:09,544| Cannot load service: liquibase.parser.ChangeLogParser: Provider liquibase.parser.core.yaml.YamlChangeLogParser could not be instantiated
2023-03-30 16:43:10 INFO - Slf4JLogger.log(43) |2023-03-30T22:43:10,036| Reading from liquibasechangelog
2023-03-30 16:43:10 INFO - Slf4JLogger.log(43) |2023-03-30T22:43:10,313| Successfully released change log lock
2023-03-30 16:43:10 ERROR - DatabaseUpdater.executeChangelog(247) |2023-03-30T22:43:10,314| Could not release lock
2023-03-30 16:43:10 liquibase.exception.LockException: liquibase.exception.LockException: Did not update change log lock correctly.
2023-03-30 16:43:10 
2023-03-30 16:43:10 0 rows were updated instead of the expected 1 row using executor liquibase.executor.jvm.JdbcExecutor there are 1 rows in the table
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:355) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:243) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.web.filter.initialization.InitializationFilter$InitializationCompletion$1.run(InitializationFilter.java:1575) [openmrs-web-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at java.lang.Thread.run(Thread.java:750) [?:1.8.0_362]
2023-03-30 16:43:10 Caused by: liquibase.exception.LockException: Did not update change log lock correctly.
2023-03-30 16:43:10 
2023-03-30 16:43:10 0 rows were updated instead of the expected 1 row using executor liquibase.executor.jvm.JdbcExecutor there are 1 rows in the table
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:343) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     ... 4 more
2023-03-30 16:43:10 WARN - InitializationFilter$InitializationCompletion$1.run(1594) |2023-03-30T22:43:10,319| Error while trying to create tables and demo data
2023-03-30 16:43:10 org.openmrs.util.DatabaseUpdateException: There was an error while updating the database to the latest. file: org/openmrs/liquibase/snapshots/schema-only/liquibase-schema-only-2.5.x.xml. Error: liquibase.exception.DatabaseException: Expected single row from liquibase.statement.core.SelectFromDatabaseChangeLogLockStatement@2e9a91d3 but got 0
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:192) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.web.filter.initialization.InitializationFilter$InitializationCompletion$1.run(InitializationFilter.java:1575) [openmrs-web-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at java.lang.Thread.run(Thread.java:750) [?:1.8.0_362]
2023-03-30 16:43:10 Caused by: liquibase.exception.LockException: liquibase.exception.DatabaseException: Expected single row from liquibase.statement.core.SelectFromDatabaseChangeLogLockStatement@2e9a91d3 but got 0
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.acquireLock(StandardLockService.java:293) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:211) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:224) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     ... 2 more
2023-03-30 16:43:10 Caused by: liquibase.exception.DatabaseException: Expected single row from liquibase.statement.core.SelectFromDatabaseChangeLogLockStatement@2e9a91d3 but got 0
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:183) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:194) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:189) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.acquireLock(StandardLockService.java:252) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:211) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:224) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     ... 2 more
2023-03-30 16:43:10 Caused by: liquibase.exception.DatabaseException: Empty result set, expected one row
2023-03-30 16:43:10     at liquibase.util.JdbcUtils.requiredSingleResult(JdbcUtils.java:132) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:181) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:194) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:189) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.acquireLock(StandardLockService.java:252) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:211) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:224) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     ... 2 more
2023-03-30 16:43:10 INFO - Slf4JLogger.log(43) |2023-03-30T22:43:10,397| Reading from liquibasechangelog
2023-03-30 16:43:10 INFO - Slf4JLogger.log(43) |2023-03-30T22:43:10,433| Successfully released change log lock
2023-03-30 16:43:10 ERROR - DatabaseUpdater.executeChangelog(247) |2023-03-30T22:43:10,434| Could not release lock
2023-03-30 16:43:10 liquibase.exception.LockException: liquibase.exception.LockException: Did not update change log lock correctly.
2023-03-30 16:43:10 
2023-03-30 16:43:10 0 rows were updated instead of the expected 1 row using executor liquibase.executor.jvm.JdbcExecutor there are 1 rows in the table
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:355) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:243) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) [openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.web.filter.initialization.InitializationFilter$InitializationCompletion$1.run(InitializationFilter.java:1696) [openmrs-web-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at java.lang.Thread.run(Thread.java:750) [?:1.8.0_362]
2023-03-30 16:43:10 Caused by: liquibase.exception.LockException: Did not update change log lock correctly.
2023-03-30 16:43:10 
2023-03-30 16:43:10 0 rows were updated instead of the expected 1 row using executor liquibase.executor.jvm.JdbcExecutor there are 1 rows in the table
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:343) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     ... 4 more
2023-03-30 16:43:10 WARN - InitializationFilter$InitializationCompletion$1.run(1703) |2023-03-30T22:43:10,435| Error while trying to update to the latest database version
2023-03-30 16:43:10 org.openmrs.util.DatabaseUpdateException: There was an error while updating the database to the latest. file: org/openmrs/liquibase/updates/liquibase-update-to-latest-2.6.x.xml. Error: liquibase.exception.DatabaseException: Expected single row from liquibase.statement.core.SelectFromDatabaseChangeLogLockStatement@43efc08f but got 0
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:192) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.web.filter.initialization.InitializationFilter$InitializationCompletion$1.run(InitializationFilter.java:1696) [openmrs-web-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at java.lang.Thread.run(Thread.java:750) [?:1.8.0_362]
2023-03-30 16:43:10 Caused by: liquibase.exception.LockException: liquibase.exception.DatabaseException: Expected single row from liquibase.statement.core.SelectFromDatabaseChangeLogLockStatement@43efc08f but got 0
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.acquireLock(StandardLockService.java:293) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:211) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:224) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     ... 2 more
2023-03-30 16:43:10 Caused by: liquibase.exception.DatabaseException: Expected single row from liquibase.statement.core.SelectFromDatabaseChangeLogLockStatement@43efc08f but got 0
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:183) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:194) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:189) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.acquireLock(StandardLockService.java:252) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:211) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:224) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     ... 2 more
2023-03-30 16:43:10 Caused by: liquibase.exception.DatabaseException: Empty result set, expected one row
2023-03-30 16:43:10     at liquibase.util.JdbcUtils.requiredSingleResult(JdbcUtils.java:132) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:181) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:194) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.executor.jvm.JdbcExecutor.queryForObject(JdbcExecutor.java:189) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.acquireLock(StandardLockService.java:252) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:211) ~[liquibase-core-4.4.3.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:224) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     at org.openmrs.util.DatabaseUpdater.executeChangelog(DatabaseUpdater.java:188) ~[openmrs-api-2.7.0-SNAPSHOT.jar:?]
2023-03-30 16:43:10     ... 2 more

When I go to http://localhost/openmrs/initialsetup it’s erroring on pretty much everything (Create OpenMRS tables task).

2023-03-31_08-46

When inspecting the backend container, it does seem like the JDBC driver, and the SQLite dialect are both installed and the SQLite database is mounted:

sh-4.2# find / -iname "*sqlite*" 2> /dev/null
/var/lib/yum/history/history-2023-01-26.sqlite-journal
/var/lib/yum/history/history-2023-01-26.sqlite
/usr/local/tomcat/temp/sqlite-3.41.0.0-855bf539-25bb-40fe-8d8e-396a35178c65-libsqlitejdbc.so.lck
/usr/local/tomcat/temp/sqlite-3.41.0.0-2b5e79aa-cebe-4fab-a277-7313d89f1109-libsqlitejdbc.so.lck
/usr/local/tomcat/temp/sqlite-3.41.0.0-2b5e79aa-cebe-4fab-a277-7313d89f1109-libsqlitejdbc.so
/usr/local/tomcat/temp/sqlite-3.41.0.0-855bf539-25bb-40fe-8d8e-396a35178c65-libsqlitejdbc.so
/usr/local/tomcat/webapps/openmrs/WEB-INF/lib/sqlite-jdbc-3.41.0.0.jar
/usr/local/tomcat/webapps/openmrs/WEB-INF/lib/sqlite-dialect-0.1.2.jar
/usr/bin/sqlite3
/usr/share/mime/application/x-sqlite3.xml
/usr/share/mime/application/x-kexiproject-sqlite2.xml
/usr/share/mime/application/x-sqlite2.xml
/usr/share/mime/application/x-kexiproject-sqlite3.xml
/usr/share/doc/sqlite-3.7.17
/usr/share/man/man1/sqlite3.1.gz
/usr/lib/python2.7/site-packages/yum/sqlitesack.pyc
/usr/lib/python2.7/site-packages/yum/sqlitesack.py
/usr/lib64/libsqlite3.so.0
/usr/lib64/libsqlite3.so.0.8.6
/usr/lib64/python2.7/sqlite3
/usr/lib64/python2.7/lib-dynload/_sqlite3.so
/usr/lib64/python2.7/site-packages/sqlitecachec.pyo
/usr/lib64/python2.7/site-packages/sqlitecachec.pyc
/usr/lib64/python2.7/site-packages/sqlitecachec.py
/usr/lib64/python2.7/site-packages/_sqlitecache.so
/openmrs/data/database.sqlite3
/openmrs_core/webapp/target/openmrs/WEB-INF/lib/sqlite-jdbc-3.41.0.0.jar
/openmrs_core/webapp/target/openmrs/WEB-INF/lib/sqlite-dialect-0.1.2.jar
/openmrs_core/docker-compose.sqlite.yml
sh-4.2# 

@ibacher I’m confused why this would be trying to create the tables again… but I’m guessing because it’s the first run?

I basically have 2 separate RefApps - first one is with zero modifications just so I can dump the MySQL database with all of the tables the backend modules would need - this container is already shut down as I have no need for it anymore since I have the MySQL dump already.

The second is the modifed RefApp where I mount the SQLite database to. I make all of the changes there before I build the images again and then run the application. I’m guessing as soon as I docker compose up, it starts trying to do the database migration as part of the initial setup step?

I think the simplest solution here would be to disable the initial setup from happening as that was already done before converting the MySQL db to SQLite?

Unfortunately, there’s no option that exists to just not run Liquibase, at least that I know of. We kind of need to run it every time the application starts not just to check for core stuff, but also for any updates to any modules, since people can swap those in and out.

The problem here isn’t even with trying to run any liquibase changes; liquibase uses a locking mechanism to ensure that only one instance is running at a time. This is not terribly relevant with SQLite, but it is for any client-server based DB.

Can you open the SQLite DB and check for the output of:

select * from liquibasechangeloglock;

There should be exactly one row that looks something like this:

+----+--------+-------------+----------+
| ID | LOCKED | LOCKGRANTED | LOCKEDBY |
+----+--------+-------------+----------+
|  1 |      0 | NULL        | NULL     |
+----+--------+-------------+----------+

(That’s actually from MySQL but we’ll ignore that for now). If it’s not there, please create it with this INSERT statement:

INSERT INTO liquibasechangeloglock VALUES
(1,0,NULL,NULL);

And see where that gets us.

Seems to be just right:

2023-03-31_14-08

It does indeed… Would you be able to send me a copy of the SQLite database you’re using? This is getting a bit beyond what I can troubleshoot without actually poking things.

Sure, here’s the SQLite database I am mounting. Let me know if you need anything else.