Could not open JPA EntityManager for transaction, DB connection closing during task excecution

Question

I was looking for similar problem, but each I've found is little bit different.

I'm using SpringBoot (1.5.2.RELEASE) and PostgresSQL DB (42.0.0).
I describe problem below:
I have a method which takes some entity, send it to external services, and save result to DB. Each entity is taken one by one (not in the list). This process sometimes takes couple seconds, sometimes even couple minutes (depends on entities to process).
Everything is going ok, unles sudennly an exception is thrown:

org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.TransactionException: JDBC begin transaction failed:
        at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:431)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:447)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656)
        at com.service.someClass.settings.SettingsServiceImpl$$EnhancerBySpringCGLIB$$897e9c29.getPropertySettings(<generated>)
        ..rest of stackTrace

Sometimes it takes me 2:15 (minutes:seconds), sometime 2:40 to get this exception.
After some investigation with DBeaver I've checked connections to DB with select * from pg_stat_activity;. During process excecution I was refreshing pg_stat_activity I noticed that one connection is responsible for creating transaction and commiting. In couple seconds query SET SESSION CHARACTERISTICS AS TRANSACTION READ WRITE appears for that connection. In the beginnig I can see 3 connections. During process excecutions I can see that one extra connection is being created and it reads some entity from current working table. Some time later the connection responsible for creating and commiting session disapear. Rest connections has got current query as SELECT 1 and at that moment exception in backend is thrown (which I pasted earlier).
More readable (I hope) version is below:

I've read about DB connections configuration and that sympthoms leads me to Tomcat configuration which looks like:

tomcat:
      removeAbandoned: true
      removeAbandonedTimeout: 120
      testOnBorrow: true
      validationQuery: SELECT 1;
      validationInterval: 30000
      testWhileIdle: true
      timeBetweenEvictionRunsMillis: 60000
      maxActive: 10
      initialSize: 2
      minIdle: 2
      maxIdle: 5

What was tested?
After more reading I tried to set removeAbandoned: false. Whole process was completed with no exception. What was different? After one extra connection to DB has been created and process was completed - that connection still appears in pg_stat_activity.
When I set removeAbandonedTimeout: to the lower value - process crash much faster. I've tried 60, and 10. When I set value 10, process crashed after 30seconds, second time after ~50seconds. When it's set to 120, it crash more after ~2:30-2:50 (min).
That's why I assume that somehow my main connection which does whole work (creating and commiting transaction) is (wrong or not) recognized as a abadonded connection (as I got know - not closed).
What is important? Closed connection is all the time "working" - changes value in query column and update start and end time excecution. What is now more curious why is it closed suddenly.

I'm not very experienced, but I think that maybe something wrong with TransactionManager (Spring) happends.

score 0 · Answer 1 · answered Nov 16 '20 at 14:50

After documentation research I've found out origin and solution to my problem.

In my case problem lies in Tomcat configuration and fact that my process can be executing for couple minutes.
When service starts to work it borrow one free connection to DB from connection pool. At this time a timer starts to count how much time concrete db client occupy specific connection. In fact that my connection is executing several query every 3 seconds I assumed (wrong) that by definition it cannot become abandoned.

Abandoned? So actually, what does abandoned mean? Specific connection becomes abandoned when some db clien borrows connection from connection pool, and didn't give it back for some value (removeAbandonedTimeout: (int) by default 180s). What is important? It doesn't metter how do you use that connection. If it's in idle state, or executing queries...

What helps?
In my case I definend in my .yml configuration file property:

spring:
  datasource:
    jdbcInterceptors: ResetAbandonedTimer

Which does that each time a statement is prepared or a query is executed, the timer will reset the abandon timer on the connection pool. That way even long processes (living processes) will not timed out.
I've found a stackoverflow post which is connected to my issue, and tracked me to great article where this feature is very well described

What is curious? I havn't found solution even in official Tomcat documentation. It says about using org.apache.tomcat.jdbc.pool.interceptor.ResetAbandonedTimer and what it does, but not saying what property can "turn on" this feature.

Hope it helps to someone and save time.

Could not open JPA EntityManager for transaction, DB connection closing during task excecution

1 Answers1