0

I am unable to understand the reason behind intermittent HikariCP Connection is not available.

From the logs, It doesn't look like a connection leak issue. A bigger problem is I am unable to predictably reproduce the error. Following is a sample log trace where the error starts while this gist contains it till the end.

 2017-12-12T19:31:55.958Z DEBUG <> [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
    2017-12-12T19:31:57.052Z WARN  <> [main] c.zaxxer.hikari.pool.ProxyConnection - HikariPool-1 - Connection org.postgresql.jdbc.PgConnection@1de5f0ef marked as broken because of SQLSTATE(08P01), ErrorCode(0)
    org.postgresql.util.PSQLException: Expected command status BEGIN, got EMPTY.
        at org.postgresql.core.v3.QueryExecutorImpl$1.handleCommandStatus(QueryExecutorImpl.java:515)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2180)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:288)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:430)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:356)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:168)
        at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:116)
        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:70)
        at org.hibernate.id.SequenceGenerator.generateHolder(SequenceGenerator.java:116)
        at org.hibernate.id.SequenceHiLoGenerator.generate(SequenceHiLoGenerator.java:62)
        at org.hibernate.event.internal.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:101)
        at org.hibernate.jpa.event.internal.core.JpaPersistEventListener.saveWithGeneratedId(JpaPersistEventListener.java:67)
    ... MORE DETAILS IN [GIST][1]

    2017-12-12T19:31:57.067Z ERROR <> [main] c.o.r.s.t.RAUTwitterUserService - populateFromPayload: id=128, twitter_handle=non_local, exception=org.springframework.transaction.TransactionSystemException: Could not roll back JPA transaction; nested exception is javax.persistence.PersistenceException: unexpected error when rollbacking
    2017-12-12T19:31:57.067Z INFO  <> [main] c.o.r.s.t.TwitterCollectorService - RAU from RAU service: RAU(id=129, twitter=non_global)
    2017-12-12T19:31:57.089Z DEBUG <> [HikariPool-1 connection adder] com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@419dcf40
comiventor
  • 3,922
  • 5
  • 50
  • 77
  • 1
    My guess - you’re closing the underlying connection somewhere by accident. Do you **ever** call `unwrap` on the `Connection`? – Boris the Spider Dec 13 '17 at 08:32
  • I am not using `Connection` explicitly. I am saving an entity via an entity repository inherited from `org.springframework.data.repository.CrudRepository` – comiventor Dec 13 '17 at 08:40

0 Answers0