java - 用Java多线程程序挂起的连接池

Question

我有一个24/7的Java应用程序(jdk1.5.0_19)，该应用程序是多线程的，使用OJDBC5作为oracle 11g(11.2.0.3)的通信。验证线程的内容后，每个线程都会调用一个可调用语句以进行准备，然后执行以将数据插入表中。现在在初始化时，共有Total JDBC 20连接。一段时间以来，它进展顺利，没有任何问题。

但是最近有一个实例，它只是在执行DB中的callable语句时挂断了。

2017-02-06 13:03:39,855 [Thread-1] INFO  QCCOM_SocketWorker run  - Worker thread launched.
2017-02-06 13:03:39,856 [Thread-1] INFO  QCCOM_Socket recvMessage  
2017-02-06 13:03:39,856 [Thread-1] INFO  QCCOM_SocketWorker recvRequest 
2017-02-06 13:03:39,856 [Thread-1] INFO  ProcessHandler invoke  
2017-02-06 13:03:39,856 [pool-1-thread-1] INFO  HandlerValidator validateRequest 
2017-02-06 13:03:39,857 [pool-1-thread-1] INFO  ProcessHandler process  - Processing request...
2017-02-06 13:03:39,857 [pool-2-thread-1] INFO  JDBCHelper call  - Atempting to retrieve connection.
2017-02-06 13:03:39,857 [pool-2-thread-1] INFO  JDBCHelper call  - Connection successfully retrieved
2017-02-06 13:03:39,857 [pool-1-thread-1] INFO  JDBCHelper getConnection  - Conn : oracle.jdbc.driver.LogicalConnection@4f064f06
2017-02-06 13:03:39,858 [pool-1-thread-1] INFO  JDBCServiceImpl insertBP  - Calling insert transaction stored procedure..
2017-02-06 13:03:43,856 [Thread-1] INFO  ProcessHandler invoke  - Worker Thread Timed out
2017-02-06 13:03:43,857 [Thread-1] DEBUG ProcessHandler invoke  - [java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:226), java.util.concurrent.FutureTask.get(FutureTask.java:100), ....ProcessHandler.invoke(ProcessHandler.java:114), com.qcom.qcm.qccom.QCCOM_SocketWorker.dispatch(QCCOM_SocketWorker.java:88), com.qcom.qcm.qccom.QCCOM_SocketWorker.run(QCCOM_SocketWorker.java:126)]
2017-02-06 13:03:43,857 [Thread-1] INFO  QCCOM_SocketWorker run  - Worker thread shutdown. 
2017-02-06 13:03:55,661 [pool-1-thread-1] INFO  JDBCServiceImpl insertBP  - Callable Statement successfully closed!
2017-02-06 13:03:55,661 [pool-1-thread-1] INFO  JDBCServiceImpl insertBP  - Connection successfully closed!
2017-02-06 13:03:55,662 [pool-1-thread-1] INFO  ProcessHandler process  - Connection successfully closed!

通常，交易发生的时间少于200毫秒。

2017-02-06 13:03:39,858 [pool-1-thread-1]信息JDBCServiceImpl insertBP-调用插入事务存储过程。

但是在上面的实例中，我们无法执行插入操作。

请参见下面的代码(JDBCServiceImpl insertBP)。

public synchronized void insertBP(String A, BigDecimal Num, Date Date) throws SQLException{
    CallableStatement cs = null;
    logger.info("Calling insert transaction stored procedure..");
    try{
        cs = (CallableStatement) conn.prepareCall("{"+sql+"}");
        cs.setString(1, tnxType);
        cs.setBigDecimal(2, Num);
        cs.setTimestamp(3, new Timestamp(Date.getTime()));

        cs.execute();
    } catch (SQLException sqlEx){           
        String strMessageContents = StringUtil.getFailedMessageContents(A, Num, Date);
        String strErrorMessage = "Failed to insert ";
        logger.fatal(strErrorMessage);
        aUtil.emailFatal;
        throw sqlEx;
    } finally {
        if (null!=cs){
            cs.close();
            logger.info("Callable Statement successfully closed!");
        }
        if (null!=conn){
            conn.close();
            logger.info("Connection successfully closed!");
        }
    }
}

它以某种方式卡在cs.execute ...上，然后出现工作线程超时并杀死了整个事务，但是以某种方式它并没有杀死已经启动的可调用语句。

我也有一个用于故障转移的代码，该代码将杀死主连接，通过这种方法，整个连接将被终止，从而导致成功的终止。

2017-02-06 13:03:55,661 [pool-1-thread-1]信息JDBCServiceImpl insertBP-可调用语句成功关闭!

代码如下

    if (Util.IsOffline){
    logger.info("App is Offline attempting to reestablish connection.");
    Util.destroyHelper();
    logger.info("Previous Connection Pool Destroyed...");
    logger.info("Reinitializing Connection Pool ...");
    try {
        AppJDBCHelper helper = AppJDBCHelper.getInstance();
        if (null != helper){
            logger.info("Connected to Schema: "+helper.getSchema());
            logger.info("Connection Pool initialized ...");
            Util.IsOffline = false;
            logger.info("App has reestablished connection.");
        }
        if (null == helper){
            logger.fatal("Failed to get database connection pool ...");
            Util.destroyHelper();
        }
    } catch (SQLException e){
        logger.fatal("Failed to connect to database ...");
        logger.debug(Arrays.toString(e.getStackTrace()));
        System.out.println(" \n >>> ERROR: Failed to connect to database ..."); 
        Util.destroyHelper();
    }
}

Util的附加代码

public void destroyHelper(){
    AppJDBCHelper helper = null;
    try {
        helper = AppJDBCHelper.getInstance();
        helper.destroy();
    } catch (SQLException e) {
        logger.fatal(e);
        logger.debug(Arrays.toString(e.getStackTrace()));
    }       
}

AppJDBCHelper的附加代码

public void destroy() throws SQLException{
    DBConnectionPool pool = new DBConnectionPoolImpl();
    pool.closeConnectionPool(ods);
    helper = null;
    logger.info("AppJDBCHelper destroy() success...");
}

这两个机器位于同一交换机中，因此网络摩擦较小。
并且经检查，在此期间内没有网络问题。 DB Listener也已启动，并准备接受事务。

因此，我的主要问题是到底发生了什么，可调用语句正在挂起。

Answer 1

一种可能的方法是自下而上并首先检查数据库中是否存在问题。
如果您使用的是Oracle 11g，则有一个不错的变化，您还拥有ASH的许可证

使用以下查询检查数据库(或与您的DBA联系)，在该数据库中参数化时间间隔和连接池DBUSER。
(如果问题是过去的历史记录，请切换到包含更长时间间隔的表dba_hist_active_sess_history。

select  
SAMPLE_TIME, SQL_EXEC_ID, SESSION_ID, SESSION_SERIAL#, SQL_ID, TOP_LEVEL_SQL_ID, SQL_OPNAME,
PLSQL_ENTRY_OBJECT_ID, EVENT, BLOCKING_SESSION_STATUS, BLOCKING_SESSION, BLOCKING_SESSION_SERIAL#
select * from v$active_session_history
where sample_time between to_date('15022017 214500','ddmmyyyy hh24miss') and  to_date('15022017 215000','ddmmyyyy hh24miss')
and USER_ID in (select user_id from dba_users where username = '<your user name>')
order by session_id, SESSION_SERIAL#,SAMPLE_TIME;

这是一个示例输出，模拟被表锁阻止的 INSERT。

SAMPLE_TIME                 SESSION_ID SESSION_SERIAL# SQL_ID        TOP_LEVEL_SQL_ID SQL_OPNAME   PLSQL_ENTRY_OBJECT_ID EVENT                    BLOCKING_SESSION_STATUS BLOCKING_SESSION BLOCKING_SESSION_SERIAL#
--------------------------- ---------- --------------- ------------- ---------------- -----------  --------------------- -----------------------  ----------------------- ---------------- ------------------------
15.02.17 21:45:20,669000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:21,683000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:22,682000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:23,680000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:24,679000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:25,693000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:26,691000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 
15.02.17 21:45:27,689000000         11           10976 gr2assvfzr2v7 6j87w7zmmzpsk    INSERT                       154744 enq: TM - contention    VALID                                 13                     4283 

重要的信息是时间戳， session 标识，SQL操作(您期望插入)和EVENT。
在我的示例中，您会看到EVENT enq: TM - contention，这意味着表已锁定，并且 session 无法执行插入。
当然，您可能会看到其他事件-检查 Oracle documentation以解决问题原因。
最后，您会看到阻止状态和阻止 session ，它们可以提供解决问题的原因。

万一您看不到数据库中的任何可疑证据(阻塞或等待状态)，请继续检查您的应用程序日志。