The spring-boot-jpa pod cannot access the DB on TAP - v1.0.1

cmoulliard commented 2 years ago

Issue

The spring-boot-jpa pod cannot access the Posgtresql DB deployed on TAP - v1.0.1 using the ServiceBinding

Log of the pod

Setting Active Processor Count to 16
Calculating JVM memory based on 23525772K available memory
Calculated JVM Memory Configuration: -XX:MaxDirectMemorySize=10M -Xmx22902072K -XX:MaxMetaspaceSize=111699K -XX:ReservedCodeCacheSize=240M -Xss1M (Total Memory: 23525772K, Thread Count: 250, Loaded Class Count: 17307, Headroom: 0%)
Enabling Java Native Memory Tracking
Adding 128 container CA certificates to JVM truststore
Spring Cloud Bindings Enabled
Picked up JAVA_TOOL_OPTIONS: -Dmanagement.endpoint.health.show-details="always" -Dmanagement.endpoints.web.base-path="/actuator" -Dmanagement.endpoints.web.exposure.include="*" -Dmanagement.server.port="8080" -Dserver.port="8080" -Dserver.shutdown.grace-period="24s" -Djava.security.properties=/layers/paketo-buildpacks_bellsoft-liberica/java-security-properties/java-security.properties -XX:+ExitOnOutOfMemoryError -XX:ActiveProcessorCount=16 -XX:MaxDirectMemorySize=10M -Xmx22902072K -XX:MaxMetaspaceSize=111699K -XX:ReservedCodeCacheSize=240M -Xss1M -XX:+UnlockDiagnosticVMOptions -XX:NativeMemoryTracking=summary -XX:+PrintNMTStatistics -Dorg.springframework.cloud.bindings.boot.enable=true

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.6.3)

2022-03-02 16:20:15.530  INFO 1 --- [           main] com.example.users.UsersApplication       : Starting UsersApplication v0.0.1-SNAPSHOT using Java 11.0.13 on spring-sql-jpa-00001-deployment-68d884bb9-g7xfp with PID 1 (/workspace/BOOT-INF/classes started by cnb in /workspace)
2022-03-02 16:20:15.533  INFO 1 --- [           main] com.example.users.UsersApplication       : The following profiles are active: postgresql
2022-03-02 16:20:16.827  INFO 1 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-03-02 16:20:16.883  INFO 1 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 41 ms. Found 1 JPA repository interfaces.
2022-03-02 16:20:17.597  INFO 1 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-03-02 16:20:17.611  INFO 1 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-03-02 16:20:17.611  INFO 1 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.56]
2022-03-02 16:20:17.708  INFO 1 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-03-02 16:20:17.708  INFO 1 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2112 ms
2022-03-02 16:20:18.162  INFO 1 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-03-02 16:20:18.228  INFO 1 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.6.4.Final
2022-03-02 16:20:18.451  INFO 1 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2022-03-02 16:20:18.579  INFO 1 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-03-02 16:20:19.651 ERROR 1 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Exception during pool initialization.

org.postgresql.util.PSQLException: Connection to localhost:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:301) ~[postgresql-42.3.1.jar:42.3.1]
    at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51) ~[postgresql-42.3.1.jar:42.3.1]
    at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:225) ~[postgresql-42.3.1.jar:42.3.1]
    at org.postgresql.Driver.makeConnection(Driver.java:466) ~[postgresql-42.3.1.jar:42.3.1]
    at org.postgresql.Driver.connect(Driver.java:265) ~[postgresql-42.3.1.jar:42.3.1]
    at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138) ~[HikariCP-4.0.3.jar:na]
    at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364) ~[HikariCP-4.0.3.jar:na]
    at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206) ~[HikariCP-4.0.3.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476) ~[HikariCP-4.0.3.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561) ~[HikariCP-4.0.3.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115) ~[HikariCP-4.0.3.jar:na]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112) ~[HikariCP-4.0.3.jar:na]
    at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.6.4.Final.jar:5.6.4.Final]
    at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess.obtainConnection(JdbcEnvironmentInitiator.java:181) ~[hibernate-core-5.6.4.Final.jar:5.6.4.Final]

Workload file

apiVersion: carto.run/v1alpha1
kind: Workload
metadata:
  name: spring-sql-jpa
  labels:
    apps.tanzu.vmware.com/workload-type: web
    app.kubernetes.io/part-of: spring-sql-jpa
spec:
  env:
  - name: SPRING_PROFILES_ACTIVE
    value: postgresql
  serviceClaims:
  - name: db
    ref:
      apiVersion: sql.tanzu.vmware.com/v1
      kind: Postgres
      name: postgres-db
  source:
    git:
      url: https://github.com/sample-accelerators/spring-sql-jpa.git
      ref:
        branch: main

Secret created by the SBO

database: postgres-db
host: postgres-db.tap-demo
password: FhKznT20TKPXH119zK9r1Do6W6FoC7
port: "5432"
provider: vmware
type: postgresql
uri: postgresql://pgappuser:FhKznT20TKPXH119zK9r1Do6W6FoC7@postgres-db.tap-demo:5432/postgres-db                                                                                        username: pgappuser

Datasource as defined within the `application-postgresql.properties`

spring.datasource.url=jdbc:postgresql://localhost:5432/test
spring.datasource.username=tanzu
spring.datasource.password=s3cret
spring.datasource.driverClassName=org.postgresql.Driver

Deployment and SBO yaml

See this gist containing the YAML content of the deployment and ServiceBinding : https://gist.github.com/cmoulliard/8e1093d6a7a4aaf1909a021ad04a8ea6#file-gistfile0-txt-L303-L305

FYI: The build of the spring boot worked well using pakeeto buildpacks ad the Service Binding layer has been well added: https://gist.github.com/cmoulliard/6dc089a9e81054687decd67e7f049dfc#file-gistfile0-txt-L1525

Questions:

Why the spring boot app tries to connect to the localhost:5432 and not postgres-db.tap-demo:5432 ?
How is the binding taking place between the secret data and the properties of the file ?

trisberg commented 2 years ago

If the app tries to connect to localhost then most likely the secret wasn't mounted. This servicebinding takes place after the first deployment of the knative service, so you might have multiple revisions for the app. See if the most recent revision works. I remember seeing two or three revisions/deployments for the knative service where the last one did get the secret mounted and did connect to the database.

cmoulliard commented 2 years ago

See if the most recent revision works. I remember seeing two or three revisions/deployments for the knative service where the last one did get the secret mounted and did connect to the database.

Will this problem been fixed with TAP v1.0.2 as the error is really annoying ? @trisberg

trisberg commented 2 years ago

I agree, this is annoying. The fix won't be in 1.0.2 unfortunately. We are waiting for some changes in carvel-kapp before we can address this. I'm hoping for TAP 1.1 having a better experience.

sample-accelerators / spring-sql-jpa