系统在两个事务同步管理器日志消息“retrieved value[]for key[]”之间做什么?

jbose2ul  于 2021-07-14  发布在  Java
关注(0)|答案(0)|浏览(160)

我正在开发一个使用spring和informix数据库的javaweb应用程序。服务器与web应用程序和数据库是两种不同的机器。
我注意到其中一个sql查询在生产服务器上执行的时间比在测试服务器上执行的时间要长。我查看了日志,发现整个事务中最耗时的部分发生在事务同步管理器的两条消息之间。
这是事务的日志条目:

2021-02-23 13:04:07,968 DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] Using transaction object [org.springframework.jdbc.datasource.DataSourceTransactionManager$DataSourceTransactionObject@3f847659]
2021-02-23 13:04:07,969 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Initializing transaction synchronization
2021-02-23 13:04:07,969 DEBUG [org.springframework.transaction.interceptor.TransactionInterceptor] Getting transaction for [com.prod.service.material.MaterialService.getMaterialIds]
2021-02-23 13:04:07,969 DEBUG [com.prod.service.material.MaterialServiceImpl]  getMaterialIds 
2021-02-23 13:04:07,969 DEBUG [com.prod.dao.material.MaterialDaoJdbc]  getMaterialIds 
2021-02-23 13:04:07,969 DEBUG [com.prod.dao.material.MaterialDaoJdbc$MaterialListQuery] RdbmsOperation with SQL […] compiled
2021-02-23 13:04:07,969 DEBUG [org.springframework.jdbc.core.JdbcTemplate] Executing prepared SQL query
2021-02-23 13:04:07,969 DEBUG [org.springframework.jdbc.core.JdbcTemplate] Executing prepared SQL statement […]
2021-02-23 13:04:07,969 DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource
2021-02-23 13:04:07,969 DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] Registering transaction synchronization for JDBC Connection
2021-02-23 13:04:07,969 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Bound value [org.springframework.jdbc.datasource.ConnectionHolder@8bd3c80] for key [org.apache.tomcat.dbcp.dbcp2.BasicDataSource@16aac72f] to thread [http-nio-127.0.0.1-8080-exec-21]
2021-02-23 13:04:07,972 DEBUG [org.springframework.jdbc.core.StatementCreatorUtils] Setting SQL statement parameter value: column index 1, parameter value [2010], value class [java.lang.String], SQL type 12

* 2021-02-23 13:04:07,972 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@8bd3c80] for key [org.apache.tomcat.dbcp.dbcp2.BasicDataSource@16aac72f] bound to thread [http-nio-127.0.0.1-8080-exec-21]
* 2021-02-23 13:04:13,881 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@8bd3c80] for key [org.apache.tomcat.dbcp.dbcp2.BasicDataSource@16aac72f] bound to thread [http-nio-127.0.0.1-8080-exec-21]

2021-02-23 13:04:13,881 DEBUG [org.springframework.transaction.interceptor.TransactionInterceptor] Completing transaction for [com.prod.service.material.MaterialService.getMaterialIds]
2021-02-23 13:04:13,881 DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] Triggering beforeCommit synchronization
2021-02-23 13:04:13,881 DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] Triggering beforeCompletion synchronization
2021-02-23 13:04:13,881 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Removed value [org.springframework.jdbc.datasource.ConnectionHolder@8bd3c80] for key [org.apache.tomcat.dbcp.dbcp2.BasicDataSource@16aac72f] from thread [http-nio-127.0.0.1-8080-exec-21]
2021-02-23 13:04:13,881 DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] Returning JDBC Connection to DataSource
2021-02-23 13:04:13,881 DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] Triggering afterCommit synchronization
2021-02-23 13:04:13,881 DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] Triggering afterCompletion synchronization
2021-02-23 13:04:13,881 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Clearing transaction synchronization

sql查询本身相当复杂,返回大约2000行数据。
事务管理器和数据源指定为:

<bean id="dataSource" class="org.springframework.jdbc.datasource.DriverManagerDataSource"> 
    <property name="driverClassName"><value>com.informix.jdbc.IfxDriver</value></property> 
    <property name="url"><value>jdbc:informix-sqli://app.prod.com:11111/prod:informixserver=prod</value></property> 
    <property name="username"><value>prod</value></property> 
    <property name="password"><value>1234</value></property> 
  </bean>    

  <bean id="transactionManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
        <property name="dataSource">
          <ref bean="dataSource"/>
        </property>
      </bean>

系统是:

OS: RHEL Server 7.9
Webserver: Tomcat 9.0.34

为什么我们有来自事务管理器的这两条消息?它不是到数据源的单一连接吗?
另外,在这两条消息之间执行6秒的过程是什么?数据放在什么地方了吗?
我这样问是因为我不知道为什么在生产服务器上花费的时间更长,而在具有相同数据的测试服务器上只需要2秒(在我上面提到的两条消息之间)。
谢谢您!

编辑

正确的数据源定义如下(我以前从错误的文件复制):

<bean id="dataSource" class="org.springframework.jndi.JndiObjectFactoryBean">
    <property name="jndiName"><value>java:/comp/env/jdbc/MyDS</value></property>
  </bean>

  <bean id="transactionManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
    <property name="dataSource">
      <ref bean="dataSource"/>
    </property>
  </bean>

context.xml文件包含:

<Resource name="jdbc/MyDS"
          auth="Container" type="javax.sql.DataSource"
          driverClassName="com.informix.jdbc.IfxDriver"
          url="jdbc:informix-sqli://app.prod.com:11111/prod:informixserver=prod;ifxIFX_LOCK_MODE_WAIT=20;ifxIFX_XASPEC=Y;" 
          username="prod" password="prod"
          maxActive="100" maxIdle="25" maxWait="10000"
          removeAbandoned="true" removeAbandonedTimeout="60" logAbandoned="true"/>

暂无答案!

目前还没有任何答案,快来回答吧!

相关问题