"Could not load an entity" error when upgrading module

Tags: #<Tag:0x00007f0f1ca65680>

hello!

I am trying to upgrade the radiology module to openmrs-core 1.11.3. running jdk 6.

In my RadiologyService tests which save or discontinue a RadiologyOrder via the OrderService I get the following exception:

org.hibernate.exception.GenericJDBCException: could not load an entity: [org.openmrs.GlobalProperty#order.nextOrderNumberSeed]
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.loader.Loader.loadEntity(Loader.java:2041)
	at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:86)
	at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:76)
	at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3293)
	at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:496)
	at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:477)
	at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:227)
	at org.hibernate.event.def.DefaultLoadEventListener.lockAndLoad(DefaultLoadEventListener.java:403)
	at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:155)
	at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:1090)
	at org.hibernate.impl.SessionImpl.get(SessionImpl.java:1081)
	at org.hibernate.impl.SessionImpl.get(SessionImpl.java:1070)
	at org.openmrs.api.db.hibernate.HibernateOrderDAO.getNextOrderNumberSeedSequenceValue(HibernateOrderDAO.java:221)
	at org.openmrs.api.impl.OrderServiceImpl.getNextOrderNumberSeedSequenceValue(OrderServiceImpl.java:527)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy51.getNextOrderNumberSeedSequenceValue(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.openmrs.aop.LoggingAdvice.invoke(LoggingAdvice.java:121)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy65.getNextOrderNumberSeedSequenceValue(Unknown Source)
	at org.openmrs.api.impl.OrderServiceImpl.getNewOrderNumber(OrderServiceImpl.java:490)
	at org.openmrs.api.impl.OrderServiceImpl.saveOrderInternal(OrderServiceImpl.java:238)
	at org.openmrs.api.impl.OrderServiceImpl.saveOrder(OrderServiceImpl.java:213)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy51.saveOrder(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.openmrs.aop.LoggingAdvice.invoke(LoggingAdvice.java:121)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy65.saveOrder(Unknown Source)
	at org.openmrs.module.radiology.impl.RadiologyServiceImpl.placeRadiologyOrder(RadiologyServiceImpl.java:102)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy96.placeRadiologyOrder(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.openmrs.aop.LoggingAdvice.invoke(LoggingAdvice.java:121)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy97.placeRadiologyOrder(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy97.placeRadiologyOrder(Unknown Source)
	at org.openmrs.module.radiology.RadiologyServiceTest.placeRadiologyOrder_shouldCreateNewRadiologyOrderAndStudyGivenRadiologyOrderObject(RadiologyServiceTest.java:155)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:74)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:83)
	at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:168)
	at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:72)
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:231)
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:88)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:71)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:174)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)
Caused by: org.h2.jdbc.JdbcSQLException: Zeitüberschreitung beim Versuch die Tabelle "GLOBAL_PROPERTY" zu sperren
Timeout trying to lock table "GLOBAL_PROPERTY"; SQL statement:
select globalprop0_.property as property32_0_, globalprop0_.property_value as property2_32_0_, globalprop0_.description as descript3_32_0_, globalprop0_.datatype as datatype32_0_, globalprop0_.datatype_config as datatype5_32_0_, globalprop0_.preferred_handler as preferred6_32_0_, globalprop0_.handler_config as handler7_32_0_, globalprop0_.uuid as uuid32_0_ from global_property globalprop0_ where globalprop0_.property=? for update [50200-173]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:331)
	at org.h2.message.DbException.get(DbException.java:171)
	at org.h2.message.DbException.get(DbException.java:148)
	at org.h2.table.RegularTable.doLock(RegularTable.java:521)
	at org.h2.table.RegularTable.lock(RegularTable.java:455)
	at org.h2.table.TableFilter.lock(TableFilter.java:145)
	at org.h2.command.dml.Select.queryWithoutCache(Select.java:611)
	at org.h2.command.dml.Query.query(Query.java:314)
	at org.h2.command.dml.Query.query(Query.java:284)
	at org.h2.command.dml.Query.query(Query.java:36)
	at org.h2.command.CommandContainer.query(CommandContainer.java:91)
	at org.h2.command.Command.executeQuery(Command.java:195)
	at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:106)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
	at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
	at org.hibernate.loader.Loader.getResultSet(Loader.java:1953)
	at org.hibernate.loader.Loader.doQuery(Loader.java:802)
	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)
	at org.hibernate.loader.Loader.loadEntity(Loader.java:2037)
	... 153 more

this leads me to this section in the openmrs-core code

	/**
 * @see org.openmrs.api.db.OrderDAO#getNextOrderNumberSeedSequenceValue()
 */
@Override
public Long getNextOrderNumberSeedSequenceValue() {
	Criteria searchCriteria = sessionFactory.getCurrentSession().createCriteria(GlobalProperty.class);
	searchCriteria.add(Restrictions.eq("property", OpenmrsConstants.GP_NEXT_ORDER_NUMBER_SEED));
	GlobalProperty globalProperty = (GlobalProperty) sessionFactory.getCurrentSession().get(GlobalProperty.class,
	    OpenmrsConstants.GP_NEXT_ORDER_NUMBER_SEED, LockOptions.UPGRADE);

which I guess must be the culprit.

How do I go about this? Not sure if it has something to do with it but I do not have a custom OrderNumberGenerator, so I would hope that the default implementation would be used as well in the ContextSensitive tests.

Hi @teleivo, I’ve seen this occur intermittently. Have you tried the workaround mentioned here - http://listarchives.openmrs.org/Limitations-of-H2-for-unit-tests-td7560958.html

Another thing that might help is adding a timeout like jdbc:h2:test;LOCK_TIMEOUT=5000 in the Runtime properties URL, similar to what darius mentioned in the above linked email thread

1 Like

thanks for the tip, unfortunately it does not get rid of

ERROR - JDBCExceptionReporter.logExceptions(234) |2015-10-09 12:41:29,264| Timeout trying to lock table “GLOBAL_PROPERTY”; SQL statement:

I also increased the LOCK_TIMEOUT from initially 1s to 500s, but no change.

@sunbiz do you have another idea of what might cause this? Or @darius do you remember anything else you did to get rid of this error?

If nothing works, there’s a hacky solution:

If DBdialect = ‘H2’ Then Get property without locking Else Get property with lock End

If we had wrappers around Hibernate objects (decorator pattern) we could centralize this kind of stuff.

1 Like

In his very post, he responded with the solution: http://listarchives.openmrs.org/Limitations-of-H2-for-unit-tests-td7560958.html

I added the snippet Darius suggests as solution but it just didn’t solve the issue in my case.

But did it change the property? The H2 database credentials are hardcoded, they don’t come from the runtime properties IIRC.

yes it did change the property

from: jdbc:h2:mem:openmrs;DB_CLOSE_DELAY=30;LOCK_TIMEOUT=10000

to: jdbc:h2:mem:openmrs;DB_CLOSE_DELAY=30;LOCK_TIMEOUT=10000;MVCC=TRUE

this is the code I added to my RadiologyServiceComponentTest as suggested by @darius

	@Override
public Properties getRuntimeProperties() {
	Properties result = super.getRuntimeProperties();
	String url = result.getProperty(Environment.URL);
	if (url.contains("jdbc:h2:") && !url.contains(";MVCC=TRUE")) {
		result.setProperty(Environment.URL, url + ";MVCC=TRUE");
	}
	return result;
}

what happens now is that the RadiologyServiceComponentTest pass if I only run the unit tests of this file alone. before adding the snippet all tests which touch code calling orderService.saveOrder fail (see stacktrace on my first post), so thats better.

But, if I run all tests of my api, I am back where I started, the same tests fail again!

Why does it make a difference if I run the tests of one class and then run tests of all classes. Shouldnt they be independent? Fresh DB gets set up for every unit test?

Did you @teleivo obtain a final solution? @darius’s hack is not working for me as well

more suggestions at https://groups.google.com/forum/#!topic/h2-database/OG086NDeItQ couldn’t help me to resolve this

Dear @k_joseph

here is the diff of when I fixed the issue:

it is actually the same as posted above

not sure why exactly, but it is working now. I am sorry that I dont have more insight for you.

1 Like

Sure, that still fails for me; with URL: jdbc:h2:mem:openmrs;DB_CLOSE_DELAY=30;LOCK_TIMEOUT=10000;MVCC=TRUE

Well solved after removing the line; executeDataSet("org/openmrs/include/standardTestDataset.xml"); from my test which is already loaded at:

Actually, it looks like we don’t need the @darius’s fix at-all after making the above change.

+1 to @dkayiwa