Spring需要很长时间才能返回单例bean的缓存实例-transactionManager答案

【问题标题】：Spring taking long time to return cached instance of singleton bean - transactionManagerSpring需要很长时间才能返回单例bean的缓存实例-transactionManager
【发布时间】：2014-09-24 08:44:28
【问题描述】：

所有 API 调用都需要很长时间才能响应，因为 Spring 需要很长时间才能返回单例 bean 的缓存实例 - transactionManager。请查看日志，此行为对于每个请求都是一致的。

014-09-24 08:09:02,239 DEBUG servlet.DispatcherServlet - DispatcherServlet with name 'appServlet' processing GET request for [/emsp/locations]
2014-09-24 08:09:02,239 DEBUG annotation.RequestMappingHandlerMapping - Looking up handler method for path /locations
2014-09-24 08:09:02,239 DEBUG annotation.RequestMappingHandlerMapping - Did not find handler method for [/locations]
2014-09-24 08:09:02,239 DEBUG servlet.DispatcherServlet - Last-Modified value for [/emsp/locations] is: -1
2014-09-24 08:09:02,240 DEBUG support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'integrationEvaluationContext'
2014-09-24 08:09:02,241 DEBUG support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'endpointLookupService'
2014-09-24 08:09:07,407 DEBUG support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'txManager'  
2014-09-24 08:09:07,407 DEBUG hibernate4.HibernateTransactionManager - Creating new transaction with name [com.***.emsp.service.impl.EndpointLookupServiceImpl.getEndpointLocations]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; ''
2014-09-24 08:09:07,407 DEBUG hibernate4.HibernateTransactionManager - Opened new Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[insertions=[] updates=[] deletions=[] orphanRemovals=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[] collectionQueuedOps=[] unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])] for Hibernate transaction
2014-09-24 08:09:07,407 DEBUG hibernate4.HibernateTransactionManager - Preparing JDBC Connection of Hibernate Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[insertions=[] updates=[] deletions=[] orphanRemovals=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[] collectionQueuedOps=[] unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])]
2014-09-24 08:09:07,407 DEBUG internal.LogicalConnectionImpl - Obtaining JDBC connection
2014-09-24 08:09:07,407 DEBUG resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@7cfea9ab [managed: 1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@6a4d7764)
2014-09-24 08:09:07,407 DEBUG internal.LogicalConnectionImpl - Obtained JDBC connection
2014-09-24 08:09:07,407 DEBUG spi.AbstractTransactionImpl - begin
2014-09-24 08:09:07,408 DEBUG jdbc.JdbcTransaction - initial autocommit status: true
2014-09-24 08:09:07,408 DEBUG jdbc.JdbcTransaction - disabling autocommit
2014-09-24 08:09:07,408 DEBUG hibernate4.HibernateTransactionManager - Exposing Hibernate transaction as JDBC transaction [com.mchange.v2.c3p0.impl.NewProxyConnection@3c0b2e6e]
2014-09-24 08:09:07,408 INFO  impl.EndpointLookupServiceImpl - EndpointLookupServiceImpl::getEndpointLocations - called (Custom log - after this is almost instantaneous)

如果您在上面的行中特别看到这两行 - 有 5 秒的延迟 - 一段时间后它会持续增加，但一旦重新启动 tomcat 就会下降。

2014-09-24 08:09:02,241 DEBUG support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'endpointLookupService'
2014-09-24 08:09:07,407 DEBUG support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'txManager'

我的弹簧配置

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:context="http://www.springframework.org/schema/context"
    xmlns:tx="http://www.springframework.org/schema/tx" xmlns:jdbc="http://www.springframework.org/schema/jdbc"
    xsi:schemaLocation="
        http://www.springframework.org/schema/jdbc http://www.springframework.org/schema/jdbc/spring-jdbc-3.0.xsd
        http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.0.xsd
        http://www.springframework.org/schema/tx http://www.springframework.org/schema/tx/spring-tx-3.0.xsd
        http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.0.xsd">


    <context:component-scan base-package="com.****.emsp" />
    <!-- Transaction Manager Declaration -->
    <bean id="txManager"
        class="org.springframework.orm.hibernate4.HibernateTransactionManager">
        <property name="sessionFactory">
            <ref bean="sessionFactory" />
        </property>
    </bean>
    <tx:annotation-driven transaction-manager="txManager" />

    <bean id="dataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource"
        destroy-method="close">
        <property name="driverClass" value="com.mysql.jdbc.Driver" />
        <property name="jdbcUrl" value="jdbc:mysql://localhost:3306/emsp" />
        <property name="user" value="***" />
        <property name="password" value="***" />
        <!-- C3P0 properties -->
        <property name="acquireIncrement" value="1" />
        <property name="minPoolSize" value="1" />
        <property name="maxPoolSize" value="20" />
        <property name="maxIdleTime" value="300" />
        <property name="idleConnectionTestPeriod" value="3000" />
        <!--property name="testConnectionOnCheckout" value="true" /> <property 
            name="preferredTestQuery" value="select 1;" / -->
    </bean>

    <bean id="sessionFactory"
        class="org.springframework.orm.hibernate4.LocalSessionFactoryBean">
        <property name="dataSource" ref="dataSource" />
        <property name="packagesToScan" value="com.****.emsp.entity" />
        <property name="hibernateProperties">
            <value>
                hibernate.dialect=org.hibernate.dialect.MySQLDialect
                hibernate.show_sql=false
                hibernate.hbm2ddl.auto=update
            </value>
        </property>
    </bean>
</beans>

我正在为涉及数据库事务的服务 API 使用 @Transactional 注释。

请建议如何进行调试。如果需要任何其他信息，也请告诉我。

请求处理代码：

@Service
public class EndpointLookupServiceImpl implements EndpointLookupService {
    private static final Logger logger = Logger
            .getLogger(EndpointLookupServiceImpl.class);

    @Autowired
    EndpointLocationDaoImpl endpointLoctionDao;
    @Autowired
    SsidDaoImpl ssidDao;

    @Override
    @Transactional
    public EndpointLocationsResp getEndpointLocations(
            String xJwtAssertionHeader, Map<String, List<String>> reqParams) {
        logger.info("EndpointLookupServiceImpl::getEndpointLocations - called with xJwtAssertionHeader:"
                + xJwtAssertionHeader + " reqParams:" + reqParams);

        .....
    }
}

使用 spring 集成作为控制器来调用服务：

<int-http:inbound-gateway id="endpointLocById"
        request-channel="endpointLocByIdIn"
        supported-methods="GET"
        path="/locations/{locationId}"
        mapped-request-headers="*"
        payload-expression="#pathVariables.locationId" >
    </int-http:inbound-gateway> 
    <int:channel id="endpointLocByIdIn"/>   
    <int:service-activator input-channel="endpointLocByIdIn" expression="@endpointLookupService.getEndpointLocationByLocationId(headers['x-jwt-assertion'], payload)" output-channel="out" />

【问题讨论】：

请添加请求处理代码。您不是每次需要 bean 时都创建一个新的上下文实例吗？
@M.Deinum 不，我不是每次都创建上下文的新实例。我正在将请求处理代码添加到原始消息本身，请看一下。期待您的回复。
这不是我感兴趣的控制器/处理程序的服务。另外，您的服务可能应该依赖于接口EndpointLocationDao，而不是像EndpointLocationDaoImpl这样的具体实现
@M.Deinum 我正在使用 spring 集成来调用我的服务。将此也添加到原始帖子中。我也打算更改 EndpointLocationDao 而不是 EndpointLocationDaoImpl。
嗯，好的。变得更有趣:)。看起来有什么东西阻止了处理。您自己没有搞乱连接或休眠会话吗？基于连接池看起来有些耗尽或阻塞，您的 MySQL 实例可以处理那么多连接吗？

标签： spring hibernate annotations transactionmanager

【解决方案1】：

在您看到阻塞之前和之后进行线程转储以查看您的主线程在做什么，Spring 在单个线程中加载 bean，因此您应该能够看到它卡在哪里并进行更多调试。

【讨论】：