본문 바로가기
IT/Java

IBATIS connection pool test

by yjacket 2011. 9. 7.
테스트 목적
Java 의 Connection 과 Oracle 의 session 간의 관계 확인

가정
IBATIS 설정 MaximumActiveConnections 까지 점차적으로 Connection 수를 증가시키면
매 증가시 마다 오라클 session 수가 늘어날 것이다.

실험

1. 연결 유지를 위한 무한루프 프로시저

CREATE OR REPLACE PROCEDURE SP_LOOP
is
begin    
    loop 
        null;
    end loop;
end;



2. SQLMap 

<sqlMap>
    <procedure id="loop">
        {call sp_loop}
    </procedure>
</sqlMap>

 
3. 5초마다 하나씩 커넥션을 늘리고, 연결정보를 출력하는 자바 어플리케이션

import java.sql.SQLException;

import com.ibatis.common.jdbc.SimpleDataSource;
import com.ibatis.sqlmap.client.SqlMapClient;

public class ConnectionTest
{
public static void main(String[] args) throws InterruptedException
{
init();
int i = 0;
while (true)
{
Thread t = new Thread(new Runnable()
{
@Override
public void run()
{
try
{
sqlMapClient.queryForList("loop");
}
catch (SQLException e)
{
e.printStackTrace();
}
}
});
System.out.println("take " + i++);
t.start();

System.out.println(((SimpleDataSource) sqlMapClient.getDataSource()).getStatus());

Thread.sleep(5000);
}
}
private static SqlMapClient sqlMapClient = null;
private static void init()
{
// IBATIS 초기화(생략)
}
}


4. 결과

테스트 어플리케이션이 실행되면 매 5초 마다 새로운 커넥션이 생성되므로
오라클에서 다음 쿼리를 이용해 session 수의 증가를 확인

SELECT status, count(*) 
FROM v$session where username='test' AND program='JDBC Thin Client' 
GROUP BY status

 
그리고 자바 어플리케이션을 실행하면 다음과 같은 로그가 나타난다.


take 0

===============================================================
 jdbcDriver                     oracle.jdbc.OracleDriver
 jdbcUrl                        jdbc:oracle:thin:test/************@127.0.0.1:1521:xe
 jdbcUsername                   test
 jdbcPassword                   ************
 poolMaxActiveConnections       50
 poolMaxIdleConnections         10
 poolMaxCheckoutTime            120000
 poolTimeToWait                 300
 poolPingEnabled                false
 poolPingQuery                  select 1 from dual
 poolPingConnectionsOlderThan   1
 poolPingConnectionsNotUsedFor  1
 --------------------------------------------------------------
 activeConnections              0
 idleConnections                0
 requestCount                   0
 averageRequestTime             0
 averageCheckoutTime            0
 claimedOverdue                 0
 averageOverdueCheckoutTime     0
 hadToWait                      0
 averageWaitTime                0
 badConnectionCount             0
===============================================================
DEBUG [00:08:40.544] {Thread-1} (Log4jImpl.java:26) Created connection 2040402337.
DEBUG [00:08:40.550] {Thread-1} (Log4jImpl.java:26) {conn-100000} Connection
DEBUG [00:08:40.554] {Thread-1} (Log4jImpl.java:26) {conn-100000} Preparing Call: {call sp_loop}
DEBUG [00:08:40.679] {Thread-1} (Log4jImpl.java:26) {pstm-100001} Executing Statement: {call sp_loop}
DEBUG [00:08:40.680] {Thread-1} (Log4jImpl.java:26) {pstm-100001} Parameters: []
DEBUG [00:08:40.680] {Thread-1} (Log4jImpl.java:26) {pstm-100001} Types: []

take 1

===============================================================
 jdbcDriver                     oracle.jdbc.OracleDriver
 jdbcUrl                        jdbc:oracle:thin:test/************@127.0.0.1:1521:xe
 jdbcUsername                   test
 jdbcPassword                   ************
 poolMaxActiveConnections       50
 poolMaxIdleConnections         10
 poolMaxCheckoutTime            120000
 poolTimeToWait                 300
 poolPingEnabled                false
 poolPingQuery                  select 1 from dual
 poolPingConnectionsOlderThan   1
 poolPingConnectionsNotUsedFor  1
 --------------------------------------------------------------
 activeConnections              1
 idleConnections                0
 requestCount                   2
 averageRequestTime             919
 averageCheckoutTime            0
 claimedOverdue                 0
 averageOverdueCheckoutTime     0
 hadToWait                      0
 averageWaitTime                0
 badConnectionCount             0
===============================================================
DEBUG [00:08:45.637] {Thread-2} (Log4jImpl.java:26) Created connection 435456241.
DEBUG [00:08:45.637] {Thread-2} (Log4jImpl.java:26) {conn-100002} Connection
DEBUG [00:08:45.638] {Thread-2} (Log4jImpl.java:26) {conn-100002} Preparing Call: {call sp_loop}
DEBUG [00:08:45.638] {Thread-2} (Log4jImpl.java:26) {pstm-100003} Executing Statement: {call sp_loop}
DEBUG [00:08:45.639] {Thread-2} (Log4jImpl.java:26) {pstm-100003} Parameters: []
DEBUG [00:08:45.639] {Thread-2} (Log4jImpl.java:26) {pstm-100003} Types: []

take 2

===============================================================
 jdbcDriver                     oracle.jdbc.OracleDriver
 jdbcUrl                        jdbc:oracle:thin:test/************@127.0.0.1:1521:xe
 jdbcUsername                   test
 jdbcPassword                   ************
 poolMaxActiveConnections       50
 poolMaxIdleConnections         10
 poolMaxCheckoutTime            120000
 poolTimeToWait                 300
 poolPingEnabled                false
 poolPingQuery                  select 1 from dual
 poolPingConnectionsOlderThan   1
 poolPingConnectionsNotUsedFor  1
 --------------------------------------------------------------
 activeConnections              2
 idleConnections                0
 requestCount                   2
 averageRequestTime             919
 averageCheckoutTime            0
 claimedOverdue                 0
 averageOverdueCheckoutTime     0
 hadToWait                      0
 averageWaitTime                0
 badConnectionCount             0
===============================================================
DEBUG [00:08:50.861] {Thread-3} (Log4jImpl.java:26) Created connection 39288954.
DEBUG [00:08:50.861] {Thread-3} (Log4jImpl.java:26) {conn-100004} Connection
DEBUG [00:08:50.862] {Thread-3} (Log4jImpl.java:26) {conn-100004} Preparing Call: {call sp_loop}
DEBUG [00:08:50.862] {Thread-3} (Log4jImpl.java:26) {pstm-100005} Executing Statement: {call sp_loop}
DEBUG [00:08:50.862] {Thread-3} (Log4jImpl.java:26) {pstm-100005} Parameters: []
DEBUG [00:08:50.863] {Thread-3} (Log4jImpl.java:26) {pstm-100005} Types: []

take 3

===============================================================
 jdbcDriver                     oracle.jdbc.OracleDriver
 jdbcUrl                        jdbc:oracle:thin:test/************@127.0.0.1:1521:xe
 jdbcUsername                   test
 jdbcPassword                   ************
 poolMaxActiveConnections       50
 poolMaxIdleConnections         10
 poolMaxCheckoutTime            120000
 poolTimeToWait                 300
 poolPingEnabled                false
 poolPingQuery                  select 1 from dual
 poolPingConnectionsOlderThan   1
 poolPingConnectionsNotUsedFor  1
 --------------------------------------------------------------
 activeConnections              3
 idleConnections                0
 requestCount                   3
 averageRequestTime             686
 averageCheckoutTime            0
 claimedOverdue                 0
 averageOverdueCheckoutTime     0
 hadToWait                      0
 averageWaitTime                0
 badConnectionCount             0
===============================================================
DEBUG [00:08:57.057] {Thread-4} (Log4jImpl.java:26) Created connection 2008400431.
DEBUG [00:08:57.058] {Thread-4} (Log4jImpl.java:26) {conn-100006} Connection
DEBUG [00:08:57.058] {Thread-4} (Log4jImpl.java:26) {conn-100006} Preparing Call: {call sp_loop}
DEBUG [00:08:57.058] {Thread-4} (Log4jImpl.java:26) {pstm-100007} Executing Statement: {call sp_loop}
DEBUG [00:08:57.059] {Thread-4} (Log4jImpl.java:26) {pstm-100007} Parameters: []
DEBUG [00:08:57.059] {Thread-4} (Log4jImpl.java:26) {pstm-100007} Types: []

.
.
.
(중략)
.
.
.


take 49

===============================================================
 jdbcDriver                     oracle.jdbc.OracleDriver
 jdbcUrl                        jdbc:oracle:thin:test/************@127.0.0.1:1521:xe
 jdbcUsername                   test
 jdbcPassword                   ************
 poolMaxActiveConnections       50
 poolMaxIdleConnections         10
 poolMaxCheckoutTime            120000
 poolTimeToWait                 300
 poolPingEnabled                false
 poolPingQuery                  select 1 from dual
 poolPingConnectionsOlderThan   1
 poolPingConnectionsNotUsedFor  1
 --------------------------------------------------------------
 activeConnections              49
 idleConnections                0
 requestCount                   49
 averageRequestTime             1653
 averageCheckoutTime            0
 claimedOverdue                 0
 averageOverdueCheckoutTime     0
 hadToWait                      0
 averageWaitTime                0
 badConnectionCount             0
===============================================================
DEBUG [00:12:59.662] {Thread-50} (Log4jImpl.java:26) Created connection 630515574.
DEBUG [00:12:59.662] {Thread-50} (Log4jImpl.java:26) {conn-100098} Connection
DEBUG [00:12:59.663] {Thread-50} (Log4jImpl.java:26) {conn-100098} Preparing Call: {call sp_loop}
DEBUG [00:12:59.663] {Thread-50} (Log4jImpl.java:26) {pstm-100099} Executing Statement: {call sp_loop}
DEBUG [00:12:59.664] {Thread-50} (Log4jImpl.java:26) {pstm-100099} Parameters: []
DEBUG [00:12:59.664] {Thread-50} (Log4jImpl.java:26) {pstm-100099} Types: []

take 50

===============================================================
 jdbcDriver                     oracle.jdbc.OracleDriver
 jdbcUrl                        jdbc:oracle:thin:test/************@127.0.0.1:1521:xe
 jdbcUsername                   test
 jdbcPassword                   ************
 poolMaxActiveConnections       50
 poolMaxIdleConnections         10
 poolMaxCheckoutTime            120000
 poolTimeToWait                 300
 poolPingEnabled                false
 poolPingQuery                  select 1 from dual
 poolPingConnectionsOlderThan   1
 poolPingConnectionsNotUsedFor  1
 --------------------------------------------------------------
 activeConnections              50
 idleConnections                0
 requestCount                   50
 averageRequestTime             1687
 averageCheckoutTime            0
 claimedOverdue                 0
 averageOverdueCheckoutTime     0
 hadToWait                      0
 averageWaitTime                0
 badConnectionCount             0
===============================================================
 
take 51
 


activeConnections 는 MaximumActiveConnections의 제한 수치인 50에서 더이상 증가하지 않고 
take 51 에서 멈춘다. 내부적으로 take51 는 다음과 같은 Stack trace 를  나타내고 있다.

Name: Thread-51
State: BLOCKED on oracle.jdbc.driver.T4CConnection@6c63a721 owned by: Thread-1
Total blocked: 1  Total waited: 0

Stack trace: 
 oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:3689)
com.ibatis.common.jdbc.SimpleDataSource.popConnection(SimpleDataSource.java:600)
   - locked java.lang.Object@7d7082d8
com.ibatis.common.jdbc.SimpleDataSource.getConnection(SimpleDataSource.java:222)
...

 
오라클의 세션수는 take n 의 n 수와 일치하며 take 51 시점의 세션수는 이미 한계치에 도달했으므로 더 이상 증가하지 않는다.

STATUS COUNT(*)
--------    ----------
ACTIVE 50



 

'IT > Java' 카테고리의 다른 글

Java 에서 엑셀 파일 읽기 : POI 와 JXL(JExcel API)  (2) 2011.12.29
Java 에서 엑셀 파일 쓰기 : POI 와 JXL(JExcel API)  (0) 2011.12.29
IBATIS MaximumIdleConnections / Connection pooling logic (SimpleDataSource)  (0) 2011.09.07
long 과 Long 의 메모리 사용량  (1) 2011.08.24
자바 이미지 처리(썸네일, 포맷변환, 리터칭등)  (0) 2011.08.20

관련글

티스토리툴바