使用@Transactional注解时方法偶发15分钟启动延迟的问题求助

我之前碰到过类似的低概率事务代理延迟问题，先帮你把场景和关键信息梳理清楚，再给出几个实际的排查方向：

Problem Overview #

在给DBServiceImpl.save()添加@Transactional注解后，出现极低概率（约1/100000）的异常：该方法会延迟**约15分钟（日志显示928787ms）**才实际启动执行，启动后仅需数毫秒就能完成。推测问题出在TaskDispatcher调用save方法的代理环节。

TaskDispatcher.java #

public class TaskDispatcher extends Thread { 
    private DBProcessor dbProcessor; 
    private ThreadPoolTaskExecutor myTaskExecutor; 
    ... 
    @Override 
    public void run() { 
        this.myTaskExecutor.execute(new Runnable() { 
            @Override 
            public void run() { 
                dbProcessor.processData(data); 
            } 
        }); 
    } 
}

DBProcessor.java #

public class DBProcessor extends ADataProcessor { 
    private DBService dbService; 
    ... 
    @Override 
    public boolean processData(Data data) throws DataProcessorException { 
        long startTime = System.currentTimeMillis(); 
        success = dbService.save(tradeReportID, translatedMessages, result); 
        logger.info("processing time : {} ms.", tradeReportID, action, (System.currentTimeMillis() - startTime)); 
        return success; 
    } 
}

DBServiceImpl.java #

public class DBServiceImpl extends CustomRepository implements DBService { 
    ... 
    @Transactional 
    public boolean save(String tradeOrderId, List<TranslatedMessage> translatedMessages, DBDealServiceResult result) throws DealProcessorException, DealProcessorExceptionNoRollback { 
        logger.info("start DB processing"); 
        ... // do some db operation 
        logger.info("finished DB processing"); 
        return success; 
    } 
}

Spring Configuration (spring.xml) #

... 
<bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager"> 
    <property name="entityManagerFactory" ref="entityManagerFactory" /> 
</bean> 
<tx:annotation-driven transaction-manager="transactionManager" /> 
<bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean"> 
    <property name="dataSource" ref="connectionPoolDataSource" /> 
    <property name="packagesToScan" value="com.mycompany.myapp.jpa.entity" /> 
    <property name="jpaVendorAdapter" ref="hibernateJpaVendorAdapter" /> 
    <property name="jpaPropertyMap"> 
        <map> 
            <entry key="hibernate.generate_statistics" value="${hibernate.generate_statistics}"/> 
            <entry key="hibernate.format_sql" value="${hibernate.format_sql}"/> 
        </map> 
    </property> 
</bean> 
<bean id="hibernateJpaVendorAdapter" class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter"> 
    <property name="showSql" value="true" /> 
    <property name="databasePlatform" value="org.hibernate.dialect.Oracle12cDialect" /> 
</bean>

Execution Logs #

2018/05/17 01:58:36.903|INFO |[myTaskExecutor-4] c.m.m.a.d.DBServiceImpl start DB processing 
2018/05/17 01:58:36.915|INFO |[myTaskExecutor-4] c.m.m.a.p.DBServiceImpl finished DB processing 
2018/05/17 01:58:36.920|INFO |[myTaskExecutor-4] c.m.m.a.d.DBProcessor processing time : 17 ms. 
2018/05/17 01:58:36.931|INFO |[myTaskExecutor-16] c.m.m.a.d.DBServiceImpl start DB processing 
2018/05/17 01:58:37.745|INFO |[myTaskExecutor-16] c.m.m.a.p.DBServiceImpl finished DB processing 
2018/05/17 01:58:37.745|INFO |[myTaskExecutor-16] c.m.m.a.d.DBProcessor processing time : 928787 ms.

关键观察：myTaskExecutor-16线程在01:58:36.931打印了start DB processing，但DBProcessor的processing time显示为928787ms（约15分钟）——这说明从processData开始计时到save方法实际启动，中间隔了15分钟，问题不是save执行慢，是save方法被调用后，过了15分钟才真正进入方法体执行。

Version Details #

spring-framework : 5.0.5.RELEASE 
spring-tx : 5.0.5.RELEASE 
spring-jdbc : 5.0.5.RELEASE 
spring-orm : 5.0.5.RELEASE 
hibernate-jpa-2.1-api : 1.0.0.Final 
hibernate-core : 5.2.7.Final 
tomcat-jdbc : 7.0.70 
oracle driver : ojdbc7 12.1.0.2

Possible Troubleshooting Directions #

1. Transaction Proxy Initialization Lock Contention
   Spring的事务代理（JdkDynamicAopProxy/CglibAopProxy）在首次创建代理对象时可能存在锁竞争。如果ThreadPoolTaskExecutor多线程并发调用save方法，极低概率下可能碰到代理类初始化时的锁等待。可以尝试：

   • 提前初始化DBServiceImpl的代理对象（比如启动时调用一个空方法），避免运行时动态初始化
   • 检查是否有自定义AOP切面和@Transactional同时作用，导致代理逻辑复杂引发锁

2. Connection Pool Blocking
   延迟可能出在获取数据库连接的阶段（这部分在@Transactional的代理逻辑里，还没进入save方法体）。检查tomcat-jdbc的配置：

   • 最大连接数是否足够？是否存在连接泄漏？
   • 连接超时时间maxWait是否设置为900000ms（15分钟）？如果连接池耗尽，线程会等待到超时才放弃，正好匹配延迟时长。

3. Hibernate EntityManagerFactory Locking
   JpaTransactionManager在获取EntityManager时，可能涉及EntityManagerFactory的锁操作。利用已开启的hibernate.generate_statistics，检查是否有EntityManager获取延迟的记录。

4. Thread Local Contention
   Spring事务绑定到ThreadLocal，如果ThreadPoolTaskExecutor的线程复用导致ThreadLocal数据清理不及时，极低概率下可能引发代理逻辑中的线程本地变量竞争。可以配置ThreadPoolTaskExecutor的taskDecorator，在每个任务执行前后清理ThreadLocal。

内容的提问来源于stack exchange，提问作者Peeratorn Ochapun