Hello all–
fyi, I think we’ve encountered a bug when upgrading to the latest version of the Metadata Mapping module.
It’s not a blocker, because I believe the fix is to simply restart tomcat (and potentially restart all modules manually), but I wanted to note it in case anyone else runs into it.
I believe the issue is caused by the changeset introduced as part of https://issues.openmrs.org/browse/MAP-7
This changeset removes the (deprecated) “Metadata Mapping” privilege from all Roles, and then removes the privilege itself.
However, looking at the logs during startup, we see the following error soon after the that privilege is deleted.
I NFO 9/28/16 9:13 PM:liquibase: ChangeSet liquibase.xml::metadatamapping-2016-02-12-1646::kosmik ran successfully in 16ms
INFO 9/28/16 9:13 PM:liquibase: Successfully released change log lock
INFO - LoggingAdvice.invoke(113) |2016-09-28 21:13:44,362| In method AdministrationService.saveGlobalProperty. Arguments: GlobalProperty=property: metadatam
apping.started value: true,
INFO - LoggingAdvice.invoke(150) |2016-09-28 21:13:44,365| Exiting method saveGlobalProperty
INFO - LoggingAdvice.invoke(113) |2016-09-28 21:13:44,369| In method AdministrationService.saveGlobalProperty. Arguments: GlobalProperty=property: metadatam
apping.mandatory value: false,
INFO - LoggingAdvice.invoke(150) |2016-09-28 21:13:44,371| Exiting method saveGlobalProperty
ERROR - Context.checkCoreDataset(1011) |2016-09-28 21:13:44,415| Error while setting core roles for openmrs system
org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.openmrs.Privilege#Metadata Mapping]
at org.hibernate.impl.SessionFactoryImpl$2.handleEntityNotFound(SessionFactoryImpl.java:435)
at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:233)
at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:285)
at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:152)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:1090)
at org.hibernate.impl.SessionImpl.internalLoad(SessionImpl.java:1038)
at org.hibernate.type.EntityType.resolveIdentifier(EntityType.java:630)
at org.hibernate.type.ManyToOneType.assemble(ManyToOneType.java:236)
at org.hibernate.collection.PersistentSet.initializeFromCache(PersistentSet.java:147)
at org.hibernate.cache.entry.CollectionCacheEntry.assemble(CollectionCacheEntry.java:58)
at org.hibernate.event.def.DefaultInitializeCollectionEventListener.initializeCollectionFromCache(DefaultInitializeCollectionEventListener.java:159)
at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:71)
at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1863)
at org.hibernate.collection.AbstractPersistentCollection.forceInitialization(AbstractPersistentCollection.java:479)
at org.hibernate.engine.StatefulPersistenceContext.initializeNonLazyCollections(StatefulPersistenceContext.java:900)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:279)
at org.hibernate.loader.Loader.doList(Loader.java:2533)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2276)
at org.hibernate.loader.Loader.list(Loader.java:2271)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:452)
at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363)
at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1268)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
at org.openmrs.api.db.hibernate.HibernateUserDAO.getAllRoles(HibernateUserDAO.java:232)
at org.openmrs.api.impl.UserServiceImpl.getAllRoles(UserServiceImpl.java:268)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
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.invoke(TransactionInterceptor.java:110)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy29.getAllRoles(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
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.invoke(TransactionInterceptor.java:110)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.openmrs.aop.LoggingAdvice.invoke(LoggingAdvice.java:118)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:50)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:50)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy30.getAllRoles(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
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.invoke(TransactionInterceptor.java:110)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy30.getAllRoles(Unknown Source)
at org.openmrs.api.context.Context.checkCoreDataset(Context.java:997)
at org.openmrs.module.ModuleFactory.startModuleInternal(ModuleFactory.java:556)
at org.openmrs.api.context.Daemon$1.run(Daemon.java:57)
It looks like this is happening when the ensureCoreDataset method is iterating through all Users and Roles to make sure all the relevant roles exist, and then comes across the “Metadata Mappiung” privilege. My guess is that one user (assumedly the admin user) is loaded into Hibernate before the liquibase changesets are run, and then the change deletes the privilege from the database, out from underneath Hibernate, and so then when Hibernate tries to access it further, it bombs.
There are chain of errors after this, and then, in our case, our distro module doesn’t start, resulting in an error when trying to load the home page.
Not sure what the fix is here–and it’s not crucial, because restarting tomcat and restarting all modules resolves the issue–but wanted other to be aware of it in case they run into it.
Take care, Mark