After OpenMRS built successfully, I attempted to deploy it. Initial Setup froze whilst attempting to write changes; killing Jetty didn’t help.
Subsequent attempts to re-deploy brought up their own error attempting to connect to the database. Sometime during this sequence of happenings I deleted the OpenMRS database.
Attempts to make OpenMRS to construct the database upon deployment are as follows
Edited installation.h2.properties
Edited hibernate.default.properties to
Use custom JDBC URL
Show SQL
Reconcile c3po max_size with max threads of database
Edited Listener.java Line#148 to set false instead of true to force build.
Regardless a fresh copy of the database is not created. The console shows a bunch of SQL queries - then hangs.
Has anybody encountered a similar problem? How does one force a DB rebuild at deploy-time?
Deleting the runtime properties file should be all you need to do to rerun the installation but this will keep around the modules and any other data stored in the application directory, if you wish to get rid of it, you can delete the entire application data directory.
Right; initialSetup ran after deleting the directory under \AppData\Roaming\OpenMRS
Except it has not completed execution yet … 8 hours down the line and the Installation Wizard output details reads as follows. How can I salvage setup at this point?
Server log file output:
INFO - LoggingAdvice.invoke(119) |2014-10-25 00:41:55,920| In method AdministrationService.saveGlobalProperty. Arguments: GlobalProperty=property: order.testSpecimenSourcesConceptUuid value: null,
INFO - LoggingAdvice.invoke(159) |2014-10-25 00:41:55,951| Exiting method saveGlobalProperty
INFO - LoggingAdvice.invoke(119) |2014-10-25 00:41:55,982| In method AdministrationService.saveGlobalProperty. Arguments: GlobalProperty=property: provider.unknownProviderUuid value: null,
INFO - LoggingAdvice.invoke(159) |2014-10-25 00:41:56,029| Exiting method saveGlobalProperty
INFO - HibernateContextDAO.updateSearchIndex(485) |2014-10-25 00:41:56,029| Updating the search index... It may take a few minutes.
@abhisheksur, you commented that you made some changes in code… can you revert that and try again? How do you run OpenMRS? Do you deploy it to Tomcat or use mvn jetty:run? Are you trying the latest code from master or some older version? Is the server process (see the windows task manager) idle or busy? Did you try restarting Windows to make sure it doesn’t hold on to any resources and blocking access to files?
@raff:
The environment at this end is Eclipse Luna; I deploy it the easy way from the context menu ‘Debug As’. In it’s turn this calls ‘mvn jetty:run’.
I trashed my dirty sand-box.
This is a fresh check-out of master from github. The processes are clean. Windows Task Manager only reports javaw, and mysqld as relevant processes. There are no other instances of java running. The MySQL client is also disconnected from the server.
The subsequent check-out, build & deploy were partially successful. Here is what the console now shows me
[INFO] Webapp directory = C:\Users\Developer\workspaceluna\openmrs\webapp\src\main\webapp
[INFO] Starting jetty 6.1.10 ...
2014-11-14 09:14:59.202::INFO: jetty-6.1.10
2014-11-14 09:15:00.121::INFO: No Transaction manager found - if your webapp requires one, please configure one.
2014-11-14 09:15:01.354:/openmrs:INFO: Set web app root system property: 'webapp.root' = [C:\Users\Developer\workspaceluna\openmrs\webapp\src\main\webapp\]
2014-11-14 09:15:01.354:/openmrs:INFO: Initializing log4j from [classpath:log4j.xml]
WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2673) |2014-11-14 09:15:01,958| Unable to find a runtime properties file at C:\Users\Developer\workspaceluna\openmrs\webapp\openmrs-runtime.properties
INFO 11/14/14 9:15 AM:liquibase: Reading from `liquibasechangelog`
WARNING 11/14/14 9:15 AM:liquibase: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
WARNING 11/14/14 9:15 AM:liquibase: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
WARNING 11/14/14 9:15 AM:liquibase: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
INFO - LocalSessionFactoryBean.buildSessionFactory(780) |2014-11-14 09:15:21,020| Building new Hibernate SessionFactory
WARN - Listener.loadBundledModules(487) |2014-11-14 09:15:32,790| Bundled module folder doesn't exist: C:\Users\Developer\workspaceluna\openmrs\webapp\src\main\webapp\WEB-INF\bundledModules
WARN - OpenmrsUtil.getRuntimePropertiesFilePathName(2673) |2014-11-14 09:15:32,790| Unable to find a runtime properties file at C:\Users\Developer\workspaceluna\openmrs\webapp\openmrs-runtime.properties
INFO 11/14/14 9:15 AM:liquibase: Reading from `liquibasechangelog`
WARNING 11/14/14 9:15 AM:liquibase: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
WARNING 11/14/14 9:15 AM:liquibase: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
WARNING 11/14/14 9:15 AM:liquibase: modifyDataType will lose primary key/autoincrement/not null settings for mysql. Use <sql> and re-specify all configuration if this is the case
INFO - HibernateContextDAO.updateSearchIndex(485) |2014-11-14 09:15:41,031| Updating the search index... It may take a few minutes.
Already 10 minutes now … Is a minimum db connection pool size necessary for the application to run successfully?
I don’t know what can be the issue other than missing privileges to write the index file if it is indeed caused by updateSearchIndex. Is C:\Users\your_user_name\Application Data\OpenMRS being created? Do you have the same issue when you try to deploy on Tomcat? Can you run in the debug mode to confirm that the application blocks at updateSearchIndex or at some later point that does not appear in logs?
This is why I found myself wondering whether it may be a configuration issue. Looking now at the generated log file under the AppData folder I see it is in fact a configuration issue. Specifically, a connection pool size/resource release issue as the DB has rejected creation of any additional connections with the message “Too many connections”.
The log file reports as follows …
WARN - BasicResourcePool$AcquireTask.run(1841) |2014-11-14 09:13:20,750| com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6ea20f02 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (5). Last acquisition attempt exception:
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Could not create connection to database server. Attempted reconnect 3 times. Giving up.
at sun.reflect.GeneratedConstructorAccessor97.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
at com.mysql.jdbc.Util.getInstance(Util.java:381)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2364)
at com.mysql.jdbc.ConnectionImpl.(ConnectionImpl.java:773)
at com.mysql.jdbc.JDBC4Connection.(JDBC4Connection.java:46)
at sun.reflect.GeneratedConstructorAccessor83.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:352)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:282)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Data source rejected establishment of connection, message from server: “Too many connections”
at sun.reflect.GeneratedConstructorAccessor97.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
at com.mysql.jdbc.Util.getInstance(Util.java:381)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1102)
at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2292)
… 16 more
INFO - HibernateContextDAO.updateSearchIndex(485) |2014-11-14 09:15:41,031| Updating the search index… It may take a few minutes.
INFO - HibernateContextDAO.updateSearchIndex(485) |2014-11-14 09:30:15,731| Updating the search index… It may take a few minutes.
15 connections is low. 151 is the default in MySQL. OpenMRS connection pool is configured to 50. If you have good reasons to keep your limit then you can adjust the pool size in hibernate.default.properties. See hibernate.c3p0.max_size=50.
To answer your original question the smallest db connections limit for OpenMRS is 50 by default. You can adjust that if you need to as I described above.
INFO - LoggingAdvice.invoke(159) |2014-11-22 16:07:13,055| Exiting method saveGlobalProperty
INFO - HibernateContextDAO.updateSearchIndex(485) |2014-11-22 16:07:13,055| Updating the search index... It may take a few minutes.
This time round when the application server was restarted, the browser opened up the authorization credentials page. Looks like I’m ready to play with the application now (+: