Spring Boot (Spring JPA) app connects to Azure PostgrestSQL on local but not on Azure App Service-CodePudding

All I did was follow the instructions on this Microsoft tutorial about Using Spring JPA with Azure Database for PostgreSQL.

I followed the tutorial step-by-step. It did work on local, but once I tried deploying to Azure App Service using the line:

mvn azure-webapp:deploy

I eneded up getting the following exceptions:

2022-06-18T14:21:47.174605421Z   .   ____          _            __ _ _
2022-06-18T14:21:47.174617722Z  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
2022-06-18T14:21:47.174625622Z ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
2022-06-18T14:21:47.174648222Z  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
2022-06-18T14:21:47.174671422Z   '  |____| .__|_| |_|_| |_\__, | / / / /
2022-06-18T14:21:47.174677723Z  =========|_|==============|___/=/_/_/_/
2022-06-18T14:21:47.181787036Z  :: Spring Boot ::                (v2.7.0)
2022-06-18T14:21:47.181816137Z
2022-06-18T14:21:48.082651314Z 2022-06-18 14:21:48.066  INFO 159 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication v0.0.1-SNAPSHOT using Java 1.8.0_312 on 159fae2381c4 with PID 159 (/local/site/wwwroot/app.jar started by root in /local/site/wwwroot)
2022-06-18T14:21:48.093277084Z 2022-06-18 14:21:48.092  INFO 159 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to 1 default profile: "default"
2022-06-18T14:21:54.072530883Z 2022-06-18 14:21:54.071  INFO 159 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-06-18T14:21:54.477825753Z 2022-06-18 14:21:54.477  INFO 159 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 310 ms. Found 1 JPA repository interfaces.
2022-06-18T14:21:59.990516309Z 2022-06-18 14:21:59.987  INFO 159 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 80 (http)
2022-06-18T14:22:00.174128684Z 2022-06-18 14:22:00.172  INFO 159 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-06-18T14:22:00.183673849Z 2022-06-18 14:22:00.182  INFO 159 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.63]
2022-06-18T14:22:01.165341623Z 2022-06-18 14:22:01.163  INFO 159 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-06-18T14:22:01.173184258Z 2022-06-18 14:22:01.172  INFO 159 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 12300 ms
2022-06-18T14:22:03.002264679Z 2022-06-18 14:22:03.001  INFO 159 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-06-18T14:22:03.789681832Z 2022-06-18 14:22:03.788  INFO 159 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.6.9.Final
2022-06-18T14:22:05.177355721Z 2022-06-18 14:22:05.176  INFO 159 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2022-06-18T14:22:06.574275239Z 2022-06-18 14:22:06.572  INFO 159 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-06-18T14:22:18.288356776Z 2022-06-18 14:22:18.286 ERROR 159 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Exception during pool initialization.
2022-06-18T14:22:18.288456678Z
2022-06-18T14:22:18.288470578Z org.postgresql.util.PSQLException: The connection attempt failed.
[removed multiple lines]

2022-06-18T14:22:18.289706498Z Caused by: java.net.SocketTimeoutException: connect timed out
2022-06-18T14:22:18.289713899Z  at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_312]
2022-06-18T14:22:18.289721599Z  at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_312]
2022-06-18T14:22:18.289729599Z  at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[na:1.8.0_312]
2022-06-18T14:22:18.289737099Z  at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[na:1.8.0_312]
2022-06-18T14:22:18.289744299Z  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_312]
2022-06-18T14:22:18.289752499Z  at java.net.Socket.connect(Socket.java:607) ~[na:1.8.0_312]
2022-06-18T14:22:18.289760299Z  at org.postgresql.core.PGStream.createSocket(PGStream.java:241) ~[postgresql-42.3.5.jar!/:42.3.5]
2022-06-18T14:22:18.289767799Z  at org.postgresql.core.PGStream.<init>(PGStream.java:98) ~[postgresql-42.3.5.jar!/:42.3.5]
2022-06-18T14:22:18.289775600Z  at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:109) ~[postgresql-42.3.5.jar!/:42.3.5]
2022-06-18T14:22:18.289783300Z  at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:235) ~[postgresql-42.3.5.jar!/:42.3.5]
2022-06-18T14:22:18.289790900Z  ... 58 common frames omitted

2022-06-18T14:22:18.313647791Z 2022-06-18 14:22:18.311  WARN 159 --- [           main] o.h.e.j.e.i.JdbcEnvironmentInitiator     : HHH000342: Could not obtain connection to query metadata

2022-06-18T14:22:18.313710892Z org.postgresql.util.PSQLException: The connection attempt failed.
2022-06-18T14:22:18.313719592Z  at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:331) ~[postgresql-42.3.5.jar!/:42.3.5]
2022-06-18T14:22:18.313749992Z  at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) ~[postgresql-42.3.5.jar!/:42.3.5]
2022-06-18T14:22:18.313759293Z  at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223) ~[postgresql-42.3.5.jar!/:42.3.5]
[removed multiple lines]

2022-06-18T14:22:18.314322302Z Caused by: java.net.SocketTimeoutException: connect timed out
2022-06-18T14:22:18.314329802Z  at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_312]
2022-06-18T14:22:18.314337202Z  at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_312]
[removed multiple lines]

2022-06-18T14:22:18.334018625Z 2022-06-18 14:22:18.333 ERROR 159 --- [           main] j.LocalContainerEntityManagerFactoryBean : Failed to initialize JPA EntityManagerFactory: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]
2022-06-18T14:22:18.345518313Z 2022-06-18 14:22:18.343  WARN 159 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]
2022-06-18T14:22:18.366638459Z 2022-06-18 14:22:18.365  INFO 159 --- [           main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2022-06-18T14:22:18.415568461Z 2022-06-18 14:22:18.414  INFO 159 --- [           main] ConditionEvaluationReportLoggingListener :
2022-06-18T14:22:18.415659562Z
2022-06-18T14:22:18.415670862Z Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2022-06-18T14:22:18.600163885Z 2022-06-18 14:22:18.599 ERROR 159 --- [           main] o.s.boot.SpringApplication               : Application run failed
2022-06-18T14:22:18.600245087Z
2022-06-18T14:22:18.600273087Z org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]
2022-06-18T14:22:18.600281587Z  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1804) ~[spring-beans-5.3.20.jar!/:5.3.20]
2022-06-18T14:22:18.600288587Z  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620) ~[spring-beans-5.3.20.jar!/:5.3.20]
2022-06-18T14:22:18.600296388Z  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) ~[spring-beans-5.3.20.jar!/:5.3.20]
[removed multiple lines]

2022-06-18T14:22:18.600490691Z Caused by: org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]
2022-06-18T14:22:18.600496791Z  at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:275) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600503291Z  at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:237) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600509391Z  at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:214) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
[removed multiple lines]

2022-06-18T14:22:18.600625493Z Caused by: org.hibernate.HibernateException: Access to DialectResolutionInfo cannot be null when 'hibernate.dialect' not set
2022-06-18T14:22:18.600631693Z  at org.hibernate.engine.jdbc.dialect.internal.DialectFactoryImpl.determineDialect(DialectFactoryImpl.java:100) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600638193Z  at org.hibernate.engine.jdbc.dialect.internal.DialectFactoryImpl.buildDialect(DialectFactoryImpl.java:54) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600644493Z  at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:138) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600650693Z  at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:35) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600656793Z  at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:101) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600663194Z  at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:263) ~[hibernate-core-5.6.9.Final.jar!/:5.6.9.Final]
2022-06-18T14:22:18.600669394Z  ... 41 common frames omitted
2022-06-18T14:22:18.600675194Z
2022-06-18T14:22:18.721869679Z Wait for pid == 159 either returned successfully or was interrupted due to a signal 159
2022-06-18T14:22:18.723175201Z Done waiting for main process. GLOBAL_PID_MAIN=159.
2022-06-18T14:22:18.723529007Z Exiting entry script!


2022-06-18T14:22:20.321Z ERROR - Container spring-boot-complete-test-app-no-db_0_3410b247 for site spring-boot-complete-test-app-no-db has exited, failing site start
2022-06-18T14:22:20.558Z ERROR - Container spring-boot-complete-test-app-no-db_0_3410b247 didn't respond to HTTP pings on port: 80, failing site start. See container logs for debugging.
2022-06-18T14:22:20.643Z INFO  - Stopping site spring-boot-complete-test-app-no-db because it failed during startup.
2022-06-18 14:22:18.286 ERROR 159 --- [main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Exception during pool initialization.


org.postgresql.util.PSQLException: The connection attempt failed.
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:331) ~[postgresql-42.3.5.jar!/:42.3.5]
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) ~[postgresql-42.3.5.jar!/:42.3.5]
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223) ~[postgresql-42.3.5.jar!/:42.3.5]
[removed multiple lines]

2022-06-18 14:22:18.311  WARN 159 --- [main] o.h.e.j.e.i.JdbcEnvironmentInitiator     : HHH000342: Could not obtain connection to query metadata


org.postgresql.util.PSQLException: The connection attempt failed.
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:331) ~[postgresql-42.3.5.jar!/:42.3.5]
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) ~[postgresql-42.3.5.jar!/:42.3.5]
[removed multiple lines]

Caused by: java.net.SocketTimeoutException: connect timed out
at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_312]
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_312]
[removed multiple lines]

2022-06-18 14:22:18.333 ERROR 159 --- [main] j.LocalContainerEntityManagerFactoryBean : Failed to initialize JPA EntityManagerFactory: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]
2022-06-18 14:22:18.343  WARN 159 --- [main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.env.spi.JdbcEnvironment]
2022-06-18 14:22:18.365  INFO 159 --- [main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2022-06-18 14:22:18.414  INFO 159 --- [main] ConditionEvaluationReportLoggingListener :


Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2022-06-18 14:22:18.599 ERROR 159 --- [main] o.s.boot.SpringApplication               : Application run failed

This really tells me that there seems to be a problem with the deployment, since the same exact code works fine when deployed on local.

CodePudding user response：

Turns out, it is not enough as of writing of this question to just modify the application.properties file as follows:

logging.level.org.hibernate.SQL=DEBUG

spring.datasource.url=jdbc:postgresql://$AZ_DATABASE_NAME.postgres.database.azure.com:5432/demo
spring.datasource.username=spring@$AZ_DATABASE_NAME
spring.datasource.password=$AZ_POSTGRESQL_PASSWORD

spring.jpa.show-sql=true
spring.jpa.hibernate.ddl-auto=create-drop

Now, you will also have to establish the connection of the Azure App Service into the database by:

Going to Azure portal
Opening the Azure App Service instance you want to connect
Go to Settings > Service Connector
Click Create and select the database and provide credentials needed to connect to that database.

Go to Azure portal > click the Azure App Service you want to connect to the database > create a connection in Service Connector