dhis2-devs team mailing list archive

Thread
Date

Permission denied for relation i18nlocale

To: DHIS 2 Developers list <dhis2-devs@xxxxxxxxxxxxxxxxxxx>
From: Timothy Harding <hardingt@xxxxxxxxx>
Date: Mon, 6 Oct 2014 16:38:33 +1100

Hello DHIS2 Developer's List

I'm attempting to spin up a couple test instances of DHIS2 inside Ubuntu
14.04 and with both 2.14 and 2.16 and am encountering some problems.

If create the postgres user (dhis) and the db (dhis2) and do nothing else,
I get the demo version (admin:district) for both 2.14 and 2.16. So tomcat
and postgresql are talking and the server is capable of starting and
serving pages. I then delete the DB, recreate a blank one and import a
database dump from our production server (version 2.14). Things go well
until I execute ./tomcat-dhis/bin/startup.sh this time, the system will
fail to start either 2.14 or 2.16. Interestingly enough, I can do the exact
same process in Windows 7 (Postgres and Tomcat again) and 2.14 starts up
without issue, but I have not tested 2.16 in Windows yet. I'm encountering
the following error after startup routine 11 of 11 is complete. I've
included a snippet below from 2.14, and have attached the entire log to
this email.

System: Ubuntu 14.04
PostgreSQL 9.3.5
Tomcat7

* ERROR 2014-10-06 16:06:51,792 ERROR: permission denied for relation
i18nlocale (SqlExceptionHelper.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:51,812
org.hibernate.exception.SQLGrammarException: could not extract ResultSet
        at
org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:122)
        at
org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49)
(...)
Caused by: org.postgresql.util.PSQLException: ERROR: permission denied for
relation i18nlocale
        at
org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2161)
        at
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1890)
(...)
Oct 06, 2014 4:06:51 PM org.apache.catalina.core.StandardContext
startInternal
SEVERE: Error listenerStart
Oct 06, 2014 4:06:51 PM org.apache.catalina.core.StandardContext
startInternal
SEVERE: Context [] startup failed due to previous errors

Any ideas or suggestions are appreciated. I'm both trying to learn how to
use Ubuntu with DHIS2 (used the following:
https://www.dhis2.org/doc/snapshot/en/implementer/html/ch08s02.html) and
attempting to test our migration from 2.14 to 2.16. Thanks!



Timothy Harding
PeaceCorps Volunteer
Republic of Vanuatu
hardingt@xxxxxxxxx
+678 5955137

Ubuntu 14.04:

Oct 06, 2014 4:05:17 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Oct 06, 2014 4:05:17 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1212 ms
Oct 06, 2014 4:05:17 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Oct 06, 2014 4:05:17 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.52 (Ubuntu)
Oct 06, 2014 4:05:17 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /home/dhis/tomcat-dhis/webapps/ROOT.war
* INFO  2014-10-06 16:05:53,958 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2014-10-06 16:05:53,965 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2014-10-06 16:05:56,989 Hibernate configuration loaded, using dialect: org.hibernate.dialect.PostgreSQLDialect (DefaultHibernateConfigurationProvider.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:13,738 HHH000388: Unsuccessful: alter table validationrulegroupmembers add constraint fk_validationrulegroupmembers_validationrulegroupid foreign key (validationgroupid) references validationrulegroup (SchemaUpdate.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:13,739 ERROR: must be owner of relation validationrulegroupmembers (SchemaUpdate.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:13,742 HHH000388: Unsuccessful: alter table validationrulegroupuserrolestoalert add constraint fk_validationrulegroupuserrolestoalert_validationgroupid foreign key (validationgroupid) references validationrulegroup (SchemaUpdate.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:13,744 ERROR: must be owner of relation validationrulegroupuserrolestoalert (SchemaUpdate.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:27,024 Found the following message senders: [org.hisp.dhis.message.EmailMessageSender@461e3c46, org.hisp.dhis.sms.SmsMessageSender@6b073ba0] (DefaultMessageService.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:36,260 Detected apps: [] (DefaultAppManager.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:38,219 Scheduled task with key: 0 0 0 ? * 1-6 and cron: 0 0 0 ? * 1-6 (SpringScheduler.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:38,221 Scheduled task with key: 0 0 0 ? * 0 and cron: 0 0 0 ? * 0 (SpringScheduler.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:43,265 Executing startup routine [1 of 11, runlevel 1]: PeriodTypePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:43,303 Executing startup routine [2 of 11, runlevel 1]: DataElementDefaultDimensionPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:43,841 Linked default category with default concept (DataElementDefaultDimensionPopulator.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:45,214 Executing startup routine [3 of 11, runlevel 2]: TableAlteror (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:48,151 Tables updated (TableAlteror.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:48,159 Executing startup routine [4 of 11, runlevel 3]: IdentityPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:49,297 Executing startup routine [5 of 11, runlevel 3]: TableCreator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:49,353 Executing startup routine [6 of 11, runlevel 4]: PatientTableAlteror (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:50,520 Inserted data into program_attributes table. (TableAlteror.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:50,526 Inserted data into program_identifiertypes table. (TableAlteror.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:50,540 Dropped program_patientattributes table. (TableAlteror.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:50,552 Dropped program_patientidentifiertypes table. (TableAlteror.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:51,542 Executing startup routine [7 of 11, runlevel 4]: MapViewUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:51,631 Executing startup routine [8 of 11, runlevel 5]: DataEntryFormUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:51,676 Upgraded custom case entry form identifiers (DataEntryFormUpgrader.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:51,678 Executing startup routine [9 of 11, runlevel 6]: ExpressionUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:51,756 Executing startup routine [10 of 11, runlevel 7]: ConfigurationPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:06:51,770 Executing startup routine [11 of 11, runlevel 7]: I18nLocalePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* WARN  2014-10-06 16:06:51,792 SQL Error: 0, SQLState: 42501 (SqlExceptionHelper.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:51,792 ERROR: permission denied for relation i18nlocale (SqlExceptionHelper.java [localhost-startStop-1])
* ERROR 2014-10-06 16:06:51,812 org.hibernate.exception.SQLGrammarException: could not extract ResultSet
        at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:122)
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:61)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:2031)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1832)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1811)
        at org.hibernate.loader.Loader.doQuery(Loader.java:899)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:341)
        at org.hibernate.loader.Loader.doList(Loader.java:2516)
        at org.hibernate.loader.Loader.doList(Loader.java:2502)
        at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2332)
        at org.hibernate.loader.Loader.list(Loader.java:2327)
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:490)
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:355)
        at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:195)
        at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1268)
        at org.hibernate.internal.QueryImpl.list(QueryImpl.java:101)
        at org.hibernate.internal.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:905)
        at org.hisp.dhis.hibernate.HibernateGenericStore.getCount(HibernateGenericStore.java:360)
        at org.hisp.dhis.i18n.DefaultI18nLocaleService.getI18nLocaleCount(DefaultI18nLocaleService.java:167)
        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: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.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at com.sun.proxy.$Proxy32.getI18nLocaleCount(Unknown Source)
        at org.hisp.dhis.startup.I18nLocalePopulator.execute(I18nLocalePopulator.java:63)
        at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:115)
        at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:85)
        at org.hisp.dhis.system.startup.StartupListener.contextInitialized(StartupListener.java:68)
        at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4973)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5467)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:632)
        at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1073)
        at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1857)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
Caused by: org.postgresql.util.PSQLException: ERROR: permission denied for relation i18nlocale
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2161)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1890)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:560)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:302)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:56)
        ... 49 more
 (StartupListener.java [localhost-startStop-1])
Oct 06, 2014 4:06:51 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Error listenerStart
Oct 06, 2014 4:06:51 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [] startup failed due to previous errors
* INFO  2014-10-06 16:06:51,913 De-registering jdbc driver: org.postgresql.Driver@16f4340e (StartupListener.java [localhost-startStop-1])
Oct 06, 2014 4:06:52 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@6670be6a]) and a value of type [org.springframework.security.core.context.SecurityContextImpl] (value [org.springframework.security.core.context.SecurityContextImpl@ffffffff: Null authentication]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
Oct 06, 2014 4:06:52 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Oct 06, 2014 4:06:52 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 95464 ms


Relevant section from Windows 7:
* INFO  2014-10-06 16:12:28,180 Executing startup routine [10 of 11, runlevel 7]: ConfigurationPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:12:28,192 Executing startup routine [11 of 11, runlevel 7]: I18nLocalePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-10-06 16:12:28,203 All startup routines done (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* WARN  2014-10-06 16:12:36,778 Did not find any ViewResolvers to delegate to; please configure them using the 'viewResolvers' property on the ContentNegotiatingViewResolver (ContentNegotiatingViewResolver.java [localhost-startStop-1])
Oct 06, 2014 4:12:36 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory C:\xampp\tomcat\webapps\docs
Oct 06, 2014 4:12:36 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory C:\xampp\tomcat\webapps\examples
Oct 06, 2014 4:12:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory C:\xampp\tomcat\webapps\host-manager
Oct 06, 2014 4:12:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory C:\xampp\tomcat\webapps\manager
Oct 06, 2014 4:12:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory C:\xampp\tomcat\webapps\ROOT
Oct 06, 2014 4:12:37 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Oct 06, 2014 4:12:37 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Oct 06, 2014 4:12:37 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 82267 ms

Follow ups

Re: Permission denied for relation i18nlocale
From: Jason Pickering, 2014-10-06