Spring Boot Application gets stuck on “Hikari-Pool

2019-07-30 07:03发布

问题:

I'm trying to run Spring Boot application connected to PostgreSQL database, but it just gets stuck and nothing goes on. HikariPool-1 - Starting... appears in logs and then nothing happens. And I deploy my Postgres DB as a docker image but when I try to restart the database, it stucks also and can't restart. And the problem appears in log is: statistics instead of current ones because stats collector is not responding

Maybe it relates with large I/O, because sometimes I need to fetch at least 65000 rows of data one time and also add pagination in the backend. Since there should have a lot of workloads to do, maybe the server is overloaded. And I find the exception on the log said using stale “statistics instead of current ones because stats collector is not responding” which is usually caused by the database is overloaded.

exec java -Dspring.profiles.active=docker -XX:+UseParallelGC -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:MinHeapFreeRatio=20 -XX:MaxHeapFreeRatio=40 -XX:+ExitOnOutOfMemoryError -cp . -jar /deployments/app.jar
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.0.1.RELEASE)
2019-05-23 00:34:21.142 INFO 1 --- [ main] com.auth.wisat.WisatApplication : Starting WisatApplication v0.1.5 on api-8554d5fd4c-wqrpb with PID 1 (/deployments/app.jar started by root in /deployments)
2019-05-23 00:34:21.144 INFO 1 --- [ main] com.auth.wisat.WisatApplication : The following profiles are active: docker
2019-05-23 00:34:21.185 INFO 1 --- [ main] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@44e81672: startup date [Thu May 23 00:34:21 GMT 2019]; root of context hierarchy
2019-05-23 00:34:23.024 INFO 1 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration$$EnhancerBySpringCGLIB$$ca1676b3] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-05-23 00:34:23.189 INFO 1 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration' of type [org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration$$EnhancerBySpringCGLIB$$62c43eed] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-05-23 00:34:23.196 INFO 1 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'objectPostProcessor' of type [org.springframework.security.config.annotation.configuration.AutowireBeanFactoryObjectPostProcessor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-05-23 00:34:23.198 INFO 1 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@173ed316' of type [org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-05-23 00:34:23.201 INFO 1 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration' of type [org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration$$EnhancerBySpringCGLIB$$8798e19f] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-05-23 00:34:23.209 INFO 1 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'methodSecurityMetadataSource' of type [org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-05-23 00:34:23.457 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2019-05-23 00:34:23.483 INFO 1 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2019-05-23 00:34:23.483 INFO 1 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet Engine: Apache Tomcat/8.5.29
2019-05-23 00:34:23.492 INFO 1 --- [ost-startStop-1] o.a.catalina.core.AprLifecycleListener : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64/server:/usr/lib/jvm/java-1.8-openjdk/jre/lib/amd64:/usr/lib/jvm/java-1.8-openjdk/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib]
2019-05-23 00:34:23.647 INFO 1 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2019-05-23 00:34:23.647 INFO 1 --- [ost-startStop-1] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 2464 ms
2019-05-23 00:34:24.528 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'characterEncodingFilter' to: [/*]
2019-05-23 00:34:24.528 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'requestContextFilter' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] .s.DelegatingFilterProxyRegistrationBean : Mapping filter: 'springSecurityFilterChain' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'httpTraceFilter' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'webMvcMetricsFilter' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'authenticationTokenFilter' to: [/*]
2019-05-23 00:34:24.529 INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean : Servlet dispatcherServlet mapped to [/]
2019-05-23 00:34:24.619 INFO 1 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...

postgres log

LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding
LOG: using stale statistics instead of current ones because stats collector is not responding

My pom.xml:

<properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <java.version>1.8</java.version>
        <springfox-swagger.version>2.9.2</springfox-swagger.version>
        <jjwt.version>0.9.0</jjwt.version>
        <postgresql.version>9.4-1206-jdbc42</postgresql.version>
    </properties>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-actuator</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-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.postgresql</groupId>
            <artifactId>postgresql</artifactId>
            <version>${postgresql.version}</version>
        </dependency>
        <!--<dependency>-->
            <!--<groupId>com.h2database</groupId>-->
            <!--<artifactId>h2</artifactId>-->
            <!--<scope>runtime</scope>-->
        <!--</dependency>-->
        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <version>1.16.22</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>javax.xml.bind</groupId>
            <artifactId>jaxb-api</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.springfox</groupId>
            <artifactId>springfox-swagger2</artifactId>
            <version>${springfox-swagger.version}</version>
        </dependency>
        <dependency>
            <groupId>io.springfox</groupId>
            <artifactId>springfox-swagger-ui</artifactId>
            <version>${springfox-swagger.version}</version>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-security</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.security</groupId>
            <artifactId>spring-security-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.jsonwebtoken</groupId>
            <artifactId>jjwt</artifactId>
            <version>${jjwt.version}</version>
        </dependency>

    </dependencies>

My apllication.properties:

spring.datasource.username=${POSTGRES_USER:postgres}
spring.datasource.password=${POSTGRES_PASSWORD:123}
spring.datasource.driver-class-name=org.postgresql.Driver
spring.datasource.platform=postgres
# Keep the connection alive if idle for a long time (needed in production)
spring.datasource.testWhileIdle=true
spring.datasource.validationQuery=SELECT 1
# ===============================
# = JPA / HIBERNATE
# ===============================
spring.jpa.generate-ddl=false
# Show or not log for each sql query
spring.jpa.show-sql=true
# Hibernate ddl auto (create, create-drop, update): with "create-drop" the database
# schema will be automatically created afresh for every start of application
spring.jpa.hibernate.ddl-auto=validate

# Naming strategy
spring.jpa.hibernate.naming.implicit-strategy=org.hibernate.boot.model.naming.ImplicitNamingStrategyLegacyHbmImpl
spring.jpa.hibernate.naming.physical-strategy=org.springframework.boot.orm.jpa.hibernate.SpringPhysicalNamingStrategy
#disable exceptions
spring.jpa.properties.hibernate.temp.use_jdbc_metadata_defaults=false


# Allows Hibernate to generate SQL optimized for a particular DBMS
spring.jpa.properties.hibernate.dialect=org.hibernate.dialect.PostgreSQLDialect

spring.jackson.serialization.WRITE_DATES_AS_TIMESTAMPS = false
spring.jackson.date-format = com.fasterxml.jackson.databind.util.ISO8601DateFormat

How can I solve the issue? basically I think it is because of the connection pool leaks, any one have experience with it? And for spring, is there a good way to design a restful API with large data request?