I can't figure out why my dockerized Spring Boot application terminates immediately after starting up. I looked into similar issues but couldn't find a reason for mine to fail yet.
The docker image runs ok locally, but when running on Azure Container Apps it does an auto-shutdown.
This is the log with Hikari on debug:
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.7.4)
2022-10-02 23:09:00.444 INFO 1 --- [ main] io.pomatti.app.books.BookApplication : Starting BookApplication v0.0.1-SNAPSHOT using Java 17.0.4.1 on app-books--sw6babs-6db8f449fb-n2pvt with PID 1 (/opt/app/*.jar started by root in /opt/app)
2022-10-02 23:09:00.509 INFO 1 --- [ main] io.pomatti.app.books.BookApplication : No active profile set, falling back to 1 default profile: "default"
2022-10-02 23:09:02.933 INFO 1 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-10-02 23:09:03.111 INFO 1 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 169 ms. Found 1 JPA repository interfaces.
2022-10-02 23:09:04.535 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2022-10-02 23:09:04.542 INFO 1 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2022-10-02 23:09:04.542 INFO 1 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.65]
2022-10-02 23:09:04.715 INFO 1 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2022-10-02 23:09:04.715 INFO 1 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 4080 ms
2022-10-02 23:09:04.927 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : Driver class com.microsoft.sqlserver.jdbc.SQLServerDriver found in Thread context class loader TomcatEmbeddedWebappClassLoader
context: ROOT
delegate: true
----------> Parent Classloader:
org.springframework.boot.loader.LaunchedURLClassLoader@28c97a5
2022-10-02 23:09:05.833 INFO 1 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-10-02 23:09:06.014 INFO 1 --- [ main] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.6.11.Final
2022-10-02 23:09:06.327 INFO 1 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2022-10-02 23:09:06.617 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : HikariPool-1 - configuration:
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : allowPoolSuspension................................false
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : autoCommit................................true
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : catalog................................none
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : connectionInitSql................................none
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : connectionTestQuery................................none
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : connectionTimeout................................30000
2022-10-02 23:09:06.620 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : dataSource................................none
2022-10-02 23:09:06.621 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : dataSourceClassName................................none
2022-10-02 23:09:06.621 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : dataSourceJNDI................................none
2022-10-02 23:09:06.621 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : dataSourceProperties................................{password=<masked>}
2022-10-02 23:09:06.621 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : driverClassName................................"com.microsoft.sqlserver.jdbc.SQLServerDriver"
2022-10-02 23:09:06.621 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : exceptionOverrideClassName................................none
2022-10-02 23:09:06.621 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : healthCheckProperties................................{}
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : healthCheckRegistry................................none
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : idleTimeout................................600000
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : initializationFailTimeout................................1
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : isolateInternalQueries................................false
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : jdbcUrl................................jdbc:sqlserver://sql-autoscale-2996.database.windows.net:1433;database=sqldb-autoscale-2996;user=dbadmin@sql-autoscale-2996;password=<masked>#777;encrypt=true;trustServerCertificate=false;hostNameInCertificate=*.database.windows.net;loginTimeout=30;
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : keepaliveTime................................0
2022-10-02 23:09:06.622 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : leakDetectionThreshold................................0
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : maxLifetime................................1800000
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : maximumPoolSize................................10
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : metricRegistry................................none
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : metricsTrackerFactory................................com.zaxxer.hikari.metrics.micrometer.MicrometerMetricsTrackerFactory@5e8a459
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : minimumIdle................................10
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : password................................<masked>
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : poolName................................"HikariPool-1"
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : readOnly................................false
2022-10-02 23:09:06.623 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : registerMbeans................................false
2022-10-02 23:09:06.624 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : scheduledExecutor................................none
2022-10-02 23:09:06.624 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : schema................................none
2022-10-02 23:09:06.624 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : threadFactory................................internal
2022-10-02 23:09:06.624 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : transactionIsolation................................default
2022-10-02 23:09:06.624 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : username................................none
2022-10-02 23:09:06.624 DEBUG 1 --- [ main] com.zaxxer.hikari.HikariConfig : validationTimeout................................5000
2022-10-02 23:09:06.624 INFO 1 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2022-10-02 23:09:07.726 DEBUG 1 --- [ main] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:1 ClientConnectionId: 1061c2f8-febf-4f1f-b9f6-86ee6dd22af4
2022-10-02 23:09:07.732 INFO 1 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2022-10-02 23:09:07.824 INFO 1 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.SQLServer2012Dialect
2022-10-02 23:09:07.832 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=1, active=1, idle=0, waiting=0)
2022-10-02 23:09:08.027 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:2 ClientConnectionId: 5035df48-1a77-406f-95b1-99d289e2d70e
2022-10-02 23:09:08.227 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:3 ClientConnectionId: 2f01f8bb-e542-4351-9b5c-dcf7cd6084ef
2022-10-02 23:09:08.411 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:4 ClientConnectionId: fd8950e7-85e8-4ae2-80be-8d88d3a7c84d
2022-10-02 23:09:08.614 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:5 ClientConnectionId: 73205252-2e69-4a7d-b347-9ba7d8e6458f
2022-10-02 23:09:08.737 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:6 ClientConnectionId: 0814ccbd-f55c-4442-925d-be9046619eb5
2022-10-02 23:09:08.921 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:7 ClientConnectionId: f5fb5f48-1c99-4b0c-9b58-828627cfaac2
2022-10-02 23:09:09.119 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:8 ClientConnectionId: 730e1bf3-1e7b-4416-980e-9a64cda711ea
2022-10-02 23:09:09.319 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:9 ClientConnectionId: 23786119-d561-4da6-a59e-08ceb76c7065
2022-10-02 23:09:09.519 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection ConnectionID:10 ClientConnectionId: 9cc6c870-b6a2-4ee3-bc06-14d81bd03471
2022-10-02 23:09:09.519 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)
2022-10-02 23:09:09.826 INFO 1 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-10-02 23:09:09.832 INFO 1 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-10-02 23:09:10.419 WARN 1 --- [ main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
2022-10-02 23:09:11.224 INFO 1 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2022-10-02 23:09:11.314 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2022-10-02 23:09:11.325 INFO 1 --- [ main] io.pomatti.app.books.BookApplication : Started BookApplication in 11.913 seconds (JVM running for 12.911)
2022-10-02 23:09:11.412 INFO 1 --- [ionShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2022-10-02 23:09:11.415 INFO 1 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2022-10-02 23:09:11.415 DEBUG 1 --- [ionShutdownHook] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Before shutdown stats (total=10, active=0, idle=10, waiting=0)
2022-10-02 23:09:11.416 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:1 ClientConnectionId: 1061c2f8-febf-4f1f-b9f6-86ee6dd22af4: (connection evicted)
2022-10-02 23:09:11.416 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:2 ClientConnectionId: 5035df48-1a77-406f-95b1-99d289e2d70e: (connection evicted)
2022-10-02 23:09:11.417 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:3 ClientConnectionId: 2f01f8bb-e542-4351-9b5c-dcf7cd6084ef: (connection evicted)
2022-10-02 23:09:11.417 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:4 ClientConnectionId: fd8950e7-85e8-4ae2-80be-8d88d3a7c84d: (connection evicted)
2022-10-02 23:09:11.418 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:5 ClientConnectionId: 73205252-2e69-4a7d-b347-9ba7d8e6458f: (connection evicted)
2022-10-02 23:09:11.418 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:6 ClientConnectionId: 0814ccbd-f55c-4442-925d-be9046619eb5: (connection evicted)
2022-10-02 23:09:11.419 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:7 ClientConnectionId: f5fb5f48-1c99-4b0c-9b58-828627cfaac2: (connection evicted)
2022-10-02 23:09:11.419 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:8 ClientConnectionId: 730e1bf3-1e7b-4416-980e-9a64cda711ea: (connection evicted)
2022-10-02 23:09:11.420 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:9 ClientConnectionId: 23786119-d561-4da6-a59e-08ceb76c7065: (connection evicted)
2022-10-02 23:09:11.420 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection ConnectionID:10 ClientConnectionId: 9cc6c870-b6a2-4ee3-bc06-14d81bd03471: (connection evicted)
2022-10-02 23:09:11.421 DEBUG 1 --- [ionShutdownHook] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - After shutdown stats (total=0, active=0, idle=0, waiting=0)
2022-10-02 23:09:11.421 INFO 1 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
My pom.xml:
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.7.4</version>
<relativePath /> <!-- lookup parent from repository -->
</parent>
<groupId>io.pomatti.app</groupId>
<artifactId>order</artifactId>
<version>0.0.1-SNAPSHOT</version>
<name>order</name>
<description>Demo project for Spring Boot</description>
<properties>
<java.version>17</java.version>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
</properties>
<dependencies>
<!-- Spring -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-data-jpa</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>com.microsoft.sqlserver</groupId>
<artifactId>mssql-jdbc</artifactId>
<version>11.2.1.jre17</version>
</dependency>
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<version>1.18.24</version>
<scope>provided</scope>
</dependency>
</dependencies>
<build>
<plugins>
<plugin>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-maven-plugin</artifactId>
</plugin>
</plugins>
</build>
</project>
Main class:
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
@SpringBootApplication
@RestController
@RequestMapping("/api/books")
public class BookApplication {
public static void main(String[] args) {
SpringApplication.run(BookApplication.class, args);
}
@Autowired
BookRepository repository;
@PostMapping("/")
public Book post(@RequestBody Book order) {
var book = new Book();
book.setName("Eternal Sunshine");
book.setAuthor("Anonymous");
return repository.save(book);
}
}
Dockerfile:
# syntax=docker/dockerfile:1
FROM eclipse-temurin:17-jdk-jammy as builder
WORKDIR /opt/app
COPY .mvn/ .mvn
COPY mvnw pom.xml ./
RUN ./mvnw dependency:go-offline
COPY ./src ./src
RUN ./mvnw clean install
FROM eclipse-temurin:17-jre-jammy
WORKDIR /opt/app
EXPOSE 8080
COPY --from=builder /opt/app/target/*.jar /opt/app/*.jar
ENTRYPOINT ["java", "-jar", "/opt/app/*.jar" ]
CodePudding user response：
Pods were being restarted due to a too short initial delay for the health probe, which I had set for 3s. I increased it to 10s and it solved the issue.
probes = [
{
type = "Liveness"
httpGet = {
path = "/actuator/health"
port = var.ingress_target_port
httpHeaders = [
{
name = "Custom-Header"
value = "Awesome"
}
]
}
initialDelaySeconds = 10
periodSeconds = 5
}
]
I've found that out by looking into the System Logs available for each container.
