Unable to connect Appfuse Spring app with Heroku Postgres database

160 views Asked by At

I'm trying to deploy the basic Appfuse Spring app to heroku. When I push the code to heroku it successfully builds, but when I try to open the page I get an Application Error page. I believe the problem is with connecting to heroku's postgres db and the app breaks at the moment first request to db is made, but I'm not really sure how to fix that.

I added this beans to my applicationContext.xml:

<bean class="java.net.URI" id="dbUrl">
    <constructor-arg value="#{systemEnvironment['DATABASE_URL']}"/>
</bean>
<bean class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close" id="dataSource">
    <property name="driverClassName" value="${org.postgresql.Driver}"/>
    <property name="url" value="#{ 'jdbc:postgresql://' + @dbUrl.getHost() + ':' + @dbUrl.getPort() + @dbUrl.getPath() }"/>
    <property name="username" value="#{ @dbUrl.getUserInfo().split(':')[0] }"/>
    <property name="password" value="#{ @dbUrl.getUserInfo().split(':')[1] }"/>
    <property name="connectionProperties" value="ssl=true;sslfactory=org.postgresql.ssl.NonValidatingFactory;"/>
</bean>

and these are the logs after successful build:

    ←[36m2015-06-14T14:30:10.945012+00:00 app[web.1]:←[0m Jun 14, 2015 2:30:10 PM org.apache.catalina.startup.ContextConfig processAnnotationsJar
←[36m2015-06-14T14:30:10.959377+00:00 app[web.1]:←[0m   at org.apache.tomcat.util.bcel.classfile.ClassParser.readID(ClassParser.java:200)
←[36m2015-06-14T14:30:10.963840+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.processAnnotationsStream(ContextConfig.java:2071)
←[36m2015-06-14T14:30:10.968017+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1330)
←[36m2015-06-14T14:30:10.964296+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.processAnnotationsUrl(ContextConfig.java:1913)
←[36m2015-06-14T14:30:10.969138+00:00 app[web.1]:←[0m   at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
←[36m2015-06-14T14:30:10.987850+00:00 app[web.1]:←[0m   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
←[36m2015-06-14T14:30:10.974187+00:00 app[web.1]:←[0m   at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
←[36m2015-06-14T14:30:10.968449+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:386)
←[36m2015-06-14T14:30:10.972076+00:00 app[web.1]:←[0m   at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
←[36m2015-06-14T14:30:10.948152+00:00 app[web.1]:←[0m java.io.EOFException
←[36m2015-06-14T14:30:10.948084+00:00 app[web.1]:←[0m SEVERE: Unable to process Jar entry [org/hibernate/type/descriptor/java/CalendarTimeTypeDescriptor.class] from Jar [jar:jndi:/localhost/WEB-INF/lib/hibernate-core-4.3.6.Final.jar!/] f
←[36m2015-06-14T14:30:10.959147+00:00 app[web.1]:←[0m   at org.apache.tomcat.util.bcel.classfile.FastDataInputStream.readInt(FastDataInputStream.java:145)
←[36m2015-06-14T14:30:10.959589+00:00 app[web.1]:←[0m   at org.apache.tomcat.util.bcel.classfile.ClassParser.parse(ClassParser.java:78)
←[36m2015-06-14T14:30:10.964066+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.processAnnotationsJar(ContextConfig.java:1947)
←[36m2015-06-14T14:30:10.964540+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.processAnnotations(ContextConfig.java:1898)
←[36m2015-06-14T14:30:10.968231+00:00 app[web.1]:←[0m   at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:889)
←[36m2015-06-14T14:30:10.968679+00:00 app[web.1]:←[0m   at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
←[36m2015-06-14T14:30:10.971888+00:00 app[web.1]:←[0m   at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5380)
←[36m2015-06-14T14:30:10.972496+00:00 app[web.1]:←[0m   at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
←[36m2015-06-14T14:30:10.982160+00:00 app[web.1]:←[0m   at java.util.concurrent.FutureTask.run(FutureTask.java:266)
←[36m2015-06-14T14:30:10.988068+00:00 app[web.1]:←[0m   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
←[36m2015-06-14T14:30:10.988211+00:00 app[web.1]:←[0m
←[36m2015-06-14T14:30:10.988181+00:00 app[web.1]:←[0m   at java.lang.Thread.run(Thread.java:745)
←[33m2015-06-14T14:30:19.107425+00:00 heroku[router]:←[0m at=error code=H12 desc="Request timeout" method=GET path="/" host=iin.herokuapp.com request_id=d9f43955-4856-49fd-99e3-acb2a8726026 fwd="193.135.254.174" dyno=web.1 connect=1ms se
 bytes=0
←[36m2015-06-14T14:30:21.083301+00:00 app[web.1]:←[0m Jun 14, 2015 2:30:21 PM org.apache.catalina.core.ApplicationContext log
←[36m2015-06-14T14:30:21.124977+00:00 app[web.1]:←[0m Jun 14, 2015 2:30:21 PM org.apache.catalina.core.ApplicationContext log
←[36m2015-06-14T14:30:21.084386+00:00 app[web.1]:←[0m INFO: No Spring WebApplicationInitializer types detected on classpath
←[36m2015-06-14T14:30:21.125377+00:00 app[web.1]:←[0m INFO: Initializing Spring root WebApplicationContext
←[36m2015-06-14T14:30:36.555192+00:00 app[web.1]:←[0m DEBUG [localhost-startStop-1] StartupListener.contextInitialized(47) | Initializing context...
←[36m2015-06-14T14:30:36.556130+00:00 app[web.1]:←[0m DEBUG [localhost-startStop-1] StartupListener.contextInitialized(84) | Password Encoder: BCryptPasswordEncoder
←[36m2015-06-14T14:30:36.658863+00:00 app[web.1]:←[0m Jun 14, 2015 2:30:36 PM org.apache.catalina.core.StandardContext listenerStart
←[36m2015-06-14T14:30:36.659668+00:00 app[web.1]:←[0m org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: C

←[36m2015-06-14T14:30:36.660282+00:00 app[web.1]:←[0m   at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
←[36m2015-06-14T14:30:36.661208+00:00 app[web.1]:←[0m   at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:262)
←[36m2015-06-14T14:30:36.661799+00:00 app[web.1]:←[0m   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
←[36m2015-06-14T14:30:36.662348+00:00 app[web.1]:←[0m   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
←[36m2015-06-14T14:30:36.662761+00:00 app[web.1]:←[0m   at com.sun.proxy.$Proxy126.getAllRoles(Unknown Source)
←[36m2015-06-14T14:30:36.663245+00:00 app[web.1]:←[0m   at com.isitnormal.webapp.listener.StartupListener.contextInitialized(StartupListener.java:89)
←[36m2015-06-14T14:30:36.663643+00:00 app[web.1]:←[0m   at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5492)
←[36m2015-06-14T14:30:36.663434+00:00 app[web.1]:←[0m   at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4994)
←[36m2015-06-14T14:30:36.664073+00:00 app[web.1]:←[0m   at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
←[36m2015-06-14T14:30:36.664524+00:00 app[web.1]:←[0m   at java.util.concurrent.FutureTask.run(FutureTask.java:266)
←[36m2015-06-14T14:30:36.664705+00:00 app[web.1]:←[0m   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
←[36m2015-06-14T14:30:36.664920+00:00 app[web.1]:←[0m   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
←[36m2015-06-14T14:30:36.665040+00:00 app[web.1]:←[0m   at java.lang.Thread.run(Thread.java:745)
←[36m2015-06-14T14:30:36.665279+00:00 app[web.1]:←[0m Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection
←[36m2015-06-14T14:30:36.665769+00:00 app[web.1]:←[0m   at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126)
←[36m2015-06-14T14:30:36.666251+00:00 app[web.1]:←[0m   at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:235)
←[36m2015-06-14T14:30:36.666737+00:00 app[web.1]:←[0m   at org.hibernate.internal.SessionImpl.connection(SessionImpl.java:450)
←[36m2015-06-14T14:30:36.667673+00:00 app[web.1]:←[0m   at org.apache.commons.dbcp.BasicDataSource.createConnectionFactory(BasicDataSource.java:1429)
←[36m2015-06-14T14:30:36.668124+00:00 app[web.1]:←[0m   at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
←[36m2015-06-14T14:30:36.668940+00:00 app[web.1]:←[0m   at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380)
←[36m2015-06-14T14:30:36.669947+00:00 app[web.1]:←[0m   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1571)
←[36m2015-06-14T14:30:36.555875+00:00 app[web.1]:←[0m DEBUG [localhost-startStop-1] StartupListener.contextInitialized(82) | Remember Me Enabled? true
←[36m2015-06-14T14:43:25.025089+00:00 app[web.1]:←[0m Jun 14, 2015 2:43:25 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
←[36m2015-06-14T14:43:25.042250+00:00 app[web.1]:←[0m INFO: Starting ProtocolHandler ["http-nio-49034"]
←[33m2015-06-14T14:43:25.708538+00:00 heroku[router]:←[0m at=error code=H13 desc="Connection closed without response" method=GET path="/" host=iin.herokuapp.com request_id=f3e08c1f-6dbc-41a2-b3f8-4458acdcb759 fwd="193.135.254.174" dyno=w
=10090ms status=503 bytes=0
←[36m2015-06-14T14:43:26.819183+00:00 heroku[web.1]:←[0m State changed from up to crashed
←[36m2015-06-14T14:43:26.806604+00:00 heroku[web.1]:←[0m Process exited with status 0

Also if I try to run it localy with:

foreman start web

I get successful build but the app breaks:

17:11:11 web.1  | Jun 14, 2015 5:11:11 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
17:11:11 web.1  | SEVERE: The web application [] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistere
17:11:11 web.1  | Jun 14, 2015 5:11:11 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
17:11:11 web.1  | SEVERE: The web application [] registered the JDBC driver [org.postgresql.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistere
17:11:11 web.1  | Jun 14, 2015 5:11:11 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
17:11:11 web.1  | SEVERE: The web application [] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak.
17:11:11 web.1  | Jun 14, 2015 5:11:11 PM org.apache.coyote.AbstractProtocol start
17:11:11 web.1  | INFO: Starting ProtocolHandler ["http-nio-8080"]
17:11:11 web.1  | Jun 14, 2015 5:11:11 PM org.apache.coyote.AbstractProtocol pause
17:11:11 web.1  | INFO: Pausing ProtocolHandler ["http-nio-8080"]
17:11:11 web.1  | exited with code 0
17:11:11 system | sending SIGKILL to all processes
1

There are 1 answers

0
Matt Raible On

I've used the HerokuDatabaseConfiguration.java class from JHipster and it's worked quite well for me.

https://github.com/kissaten/jhipster-example/blob/master/src/main/java/com/mycompany/myapp/config/HerokuDatabaseConfiguration.java