Spring Boot application shutting down immediately after start

Question

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" ]

have you tried this? https://stackoverflow.com/questions/61989407/springboot-app-on-azure-app-service-stops-right-after-start — fauzimh, Oct 03 '22 at 03:50
do you have any health/readiness probes enabled? I see you enable `/actuator` so it would be a good idea to add a HEALTHCHECK to your Dockerfile as well. — Mihai, Oct 03 '22 at 04:07
@fauzimh I'm not using App Service, I'm using Container Apps. It's a different service. Also I'm using docker. — Evandro Pomatti, Oct 03 '22 at 12:55
@Mihai Container Apps has native health checks "liveness" implementation, so no need for that in dockerfile. — Evandro Pomatti, Oct 03 '22 at 12:57
@EvandroPomatti only because the container is "live" does not mean the application inside is ready to receive traffic. each app works differently and listens on different ports and responds in different ways. I would be really amazed if they managed to "build this in" without any help from the developer. Plus your app receives a terminate from outside so I would still not rule this out. — Mihai, Oct 03 '22 at 13:38

Evandro Pomatti · Accepted Answer · 2022-10-06T17:15:01.103

Pods were being restarted due to a too short initial delay for the health probe, which I had set for 3s. I've 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.

Spring Boot application shutting down immediately after start

1 Answers1