0

I have a Spring boot application in version 2.1.2.RELEASE. Once a month or few weeks application crashes without any specific information in logs. Server where app is deploy is CentOS ver 7, app is launched by a systemd service.

Tried analysing heap dump, no luck, checked logs of postgres, tomcat etc. nothing there.

Stacktrace:

INFO ;read-5;523575402;2019-08-07 17:27:24,714;o.s.i.e.EventDrivenConsumer; Removing {logging-channel-adapter:_org.springframework.integration.errorLogger} as a subscriber to the 'errorChannel' channel
INFO ;read-5;523575418;2019-08-07 17:27:24,730;o.s.i.c.PublishSubscribeChannel; Channel 'application.errorChannel' has 0 subscriber(s).
INFO ;read-5;523575418;2019-08-07 17:27:24,730;o.s.i.e.EventDrivenConsumer; stopped _org.springframework.integration.errorLogger
INFO ;read-5;523575502;2019-08-07 17:27:24,814;o.s.s.c.ThreadPoolTaskScheduler; Shutting down ExecutorService 'taskScheduler'
INFO ;read-5;523575541;2019-08-07 17:27:24,853;o.s.s.c.ThreadPoolTaskExecutor; Shutting down ExecutorService 'applicationTaskExecutor'
INFO ;read-5;523575572;2019-08-07 17:27:24,884;o.s.o.j.LocalContainerEntityManagerFactoryBean; Closing JPA EntityManagerFactory for persistence unit 'default'
INFO ;read-5;523575596;2019-08-07 17:27:24,908;c.z.h.HikariDataSource; HikariPool-1 - Shutdown initiated...
INFO ;read-5;523575631;2019-08-07 17:27:24,943;c.z.h.HikariDataSource; HikariPool-1 - Shutdown completed.
WARN ;exec-8;523575668;2019-08-07 17:27:24,980;c.z.h.p.ProxyConnection; HikariPool-1 - Connection org.postgresql.jdbc.PgConnection@6ff70ea8 marked as broken because of SQLSTATE(08006), ErrorCode(0)
org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:335)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:143)
        at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:106)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:60)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:2173)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1936)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1898)

WARN ;exec-6;523575677;2019-08-07 17:27:24,989;c.z.h.p.ProxyConnection; HikariPool-1 - Connection org.postgresql.jdbc.PgConnection@71c6647 marked as broken because of SQLSTATE(08006), ErrorCode(0)
org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:335)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:143)
        at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:106)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)

WARN ;exec-8;523575721;2019-08-07 17:27:25,033;o.h.e.j.s.SqlExceptionHelper; SQL Error: 0, SQLState: 08006
WARN ;exec-6;523575721;2019-08-07 17:27:25,033;o.h.e.j.s.SqlExceptionHelper; SQL Error: 0, SQLState: 08006
ERROR;exec-8;523575721;2019-08-07 17:27:25,033;o.h.e.j.s.SqlExceptionHelper; An I/O error occurred while sending to the backend.
ERROR;exec-6;523575721;2019-08-07 17:27:25,033;o.h.e.j.s.SqlExceptionHelper; An I/O error occurred while sending to the backend.
INFO ;exec-6;523575885;2019-08-07 17:27:25,197;o.h.e.i.DefaultLoadEventListener; HHH000327: Error performing load command : org.hibernate.exception.JDBCConnectionException: could not extract ResultSet
org.hibernate.exception.JDBCConnectionException: could not extract ResultSet
        at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:115)
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)

Has anyone got idea how can I what might be going on? Last crash was 3, 4 weeks before that.

The Head Rush
  • 3,157
  • 2
  • 25
  • 45
Maciej eM
  • 41
  • 8
  • This log is not the cause of the crash but the consequence. It seems that your application is shutting down. Can you post the log before 17:27:24 ? – e.g78 Aug 09 '19 at 14:07
  • Try to log more on postgresql side: set log_statement='all' in postgresql.conf what happened before this log ? – sebge2 Aug 09 '19 at 14:11
  • Looks like you are loosing your db connection. Not sure if its related but you can try this - https://stackoverflow.com/questions/28609565/spring-is-losing-connection-to-the-db-and-does-not-recover-or-reconnect – Ajay Kumar Aug 09 '19 at 14:13

1 Answers1

0

That type of error happens when the database connection has been lost, which in turn can happen for a whole number of reasons, the most simple one being that it's being restarted after system updates or as part of a scheduled operation.

HikariCP should be able to recover according to the following link (provided that your HikariCP version is recent enough):

https://github.com/brettwooldridge/HikariCP/wiki/Rapid-Recovery

You may need to configure some properties in your pool. The full list of properties is available here:

https://github.com/brettwooldridge/HikariCP

I recommend you configure the following in HikariCP:

  • connectionTestQuery: will test the connection periodically, dropping dead connections. Use it in conjunction with socketTimeout in your PostgreSQL connection string
  • leakDetectionThreshold: will help with applications having connection leaks
Filippo Possenti
  • 1,300
  • 8
  • 18