> ## Content Index
> Fetch the complete content index at: https://www.popit.kr/llms.txt
> Use this file to discover other available public pages before exploring further.

# SQLServer JDBC의 이상한 동작
- URL: https://www.popit.kr/strange-sqlserver-jdbc-behavior/
- Published: 2017-04-23T15:01:53.000Z
- Updated: 2017-04-24T04:43:55.000Z
- Author: 김형준
- Tags: #소프트웨어, JDBC, SQLServer

DB -> HDFS 작업 관련 삽질 중인데 SQLServer의 JDBC 드라이버 동작이 생각과 다르게 동작하는 부분이 있어 공유해보려고 합니다. 공유의 목적은 이런 사항이 있으니 DB 선정 시 신중해야 할 것 같다는 것과 제가 잘못 사용하고 있는 부분이 있는지 원래 그런 것인지 독자들의 의견을 들어 보려는 것입니다.

참고로 SQLServer는 거의 사용해보지 않았고 지금도 사용하지는 않지만 HDFS로 저장해야 하는 데이터 중 SQLServer에 저장된 데이터가 있어 어쩔수 없이 보고 있습니다. 즉, SQLServer에 대해서는 하나도 모르는 상황입니다.

## SQLServer JDBC의 이상한 동작

다음과 같은 코드를 이용하여 SQLServer의 데이터를 가져오려고 하였습니다. (sqljdbc4-4.0.jar 사용)  

```java
Connection conn = DriverManager.getConnection("jdbc:sqlserver://localhost:1433;databaseName=TEST", "", "");

// created_at 컬럼에는 index 가 없음
String sql = "select * from test_table where created_at between '2017-04-01 00:00:00.000' and 2017-04-01 23:59:59.999";
Statement stmt = conn.createStatement();
LOG.info("01. Start run query");
ResultSet rs = stmt.executeQuery(sql);
LOG.info("02. Finish run query");

int count = 0;
while (true) {
 long time1 = System.currentTimeMillis();
 boolean hasNext = rs.next();
 long time2 = System.currentTimeMillis();
 if (!hasNext) {
   break;
 }
 count++;
 if (count % 1000 == 0) {
   LOG.info(count + " fetched");
 }
 if (time2 - time1 > 1000) {
   LOG.info("rs.next() is too slow: " + (time2 - time1)/1000 + " seconds. " + count + " rows fetched");
 }
}
LOG.info("03.Completed: " + count + " fetched.");
```

필자가 예상한 시나리오는 created\_at 컬럼에 index가 없기 때문에 stmt.executeQuery(sql) 이 문장 실행 시 오래 걸리고 일단 "02.Finish run query" 메시지가 나온 다음에는 빠르게 처리할 것을 예상했습니다. MySQL로 비슷한 질의를 수행하면 이렇게 동작합니다.

하지만 SQLServer에 위 프로그램을 실행하면 다음과 같은 형태로 처리합니다.

- stmt.executeQuery(sql) 수행에 수분 소요
- 일정 갯수의 row를 처리한 다음 rs.next()에서 수분 소요

위 프로그램의 로그는 다음과 같이 나타납니다.  

```
17/04/23 17:17:41 INFO: 01. Start run query
17/04/23 17:18:51 INFO: 02. Finish run query
17/04/23 17:19:02 INFO: rs.next() is too slow: 11 seconds. 16 rows fetched
17/04/23 17:19:44 INFO: rs.next() is too slow: 41 seconds. 62 rows fetched
17/04/23 17:19:48 INFO: rs.next() is too slow: 4 seconds. 85 rows fetched
17/04/23 17:19:57 INFO: rs.next() is too slow: 8 seconds. 108 rows fetched
17/04/23 17:19:59 INFO: rs.next() is too slow: 2 seconds. 131 rows fetched
17/04/23 17:20:01 INFO: rs.next() is too slow: 1 seconds. 178 rows fetched
17/04/23 17:20:12 INFO: rs.next() is too slow: 11 seconds. 201 rows fetched
17/04/23 17:20:14 INFO: rs.next() is too slow: 1 seconds. 268 rows fetched
17/04/23 17:20:38 INFO: rs.next() is too slow: 24 seconds. 290 rows fetched
17/04/23 17:20:57 INFO: rs.next() is too slow: 19 seconds. 313 rows fetched
17/04/23 17:21:06 INFO: rs.next() is too slow: 7 seconds. 382 rows fetched
17/04/23 17:21:08 INFO: rs.next() is too slow: 2 seconds. 405 rows fetched
17/04/23 17:21:14 INFO: rs.next() is too slow: 5 seconds. 497 rows fetched
17/04/23 17:21:36 INFO: rs.next() is too slow: 21 seconds. 542 rows fetched
```

이런 패턴으로 동작하는데 이를 통해 유추해보면 SQLServer는 질의 실행 시 전체 결과 Set을 서버에 가지고 있지 않고 어느 정도의 Row 갯수만 가지고 있고 클라이언트가 이를 모두 fetch 하면 다시 질의가 실행되는 이런 방식으로 동작하는 것 같다는 느낌을 받았습니다.

## SQLServer 공식 사이트에서의 가이드

구글링을 해보아도 비슷한 증상에 대한 질문만 있고 뚜렷한 답변이 없어 SQLServer 공식 사이트의 가이드를 확인해보았습니다.

- SQLServer JDBC 성능 관련 사이트: [https://docs.microsoft.com/en-us/sql/connect/jdbc/working-with-statements-and-result-sets](https://docs.microsoft.com/en-us/sql/connect/jdbc/working-with-statements-and-result-sets?ref=popit.kr)

문서 내용 중에 다음 내용을 찾았는데 default 값이라고 되어 있습니다.

> If you must deal with large result sets, consider using an adaptive response buffering by setting the connection string property responseBuffering=adaptive, which is the default mode.

아래 코드로 "adaptive" 라는 것을 확인했습니다.  

```
SQLServerStatement stmt = (SQLServerStatement)conn.createStatement();
LOG.info("ResponseBuffering: " + stmt.getResponseBuffering());
```

다시 다음 링크에서 ResponseBuffering 이라는 것에 대해 확인해보았습니다.

- ResponseBuffering: [https://docs.microsoft.com/en-us/sql/connect/jdbc/using-adaptive-buffering](https://docs.microsoft.com/en-us/sql/connect/jdbc/using-adaptive-buffering?ref=popit.kr)

글 내용 중에 ResultSet의 Cursor 타입을 적절하게 잘 사용해야 한다는 문구가 있어 Forward Only, Read Only 로 설정해 보았습니다. TYPE\_SS\_SERVER\_CURSOR\_FORWARD\_ONLY, TYPE\_SS\_DIRECT\_FORWARD\_ONLY 두가지 옵션이 있는데 TYPE\_SS\_DIRECT\_FORWARD\_ONLY 옵션의 경우 위와 동일하게 동작하는 반면 TYPE\_SS\_SERVER\_CURSOR\_FORWARD\_ONLY 를 사용하면 "ResultSet rs = stmt.executeQuery(sql);" 이 부분은 빠르게 실행됩니다. 즉 이 명령에 의해서는 실제 서버에서는 SQL이 실행되지 않고 준비만 하는 것 같습니다.  

```
17/04/23 17:39:26 INFO: ResponseBuffering: adaptive
17/04/23 17:39:26 INFO: Start run query
17/04/23 17:39:26 INFO: Finish run query
17/04/23 17:39:45 INFO: rs.next() is too slow: 18 seconds. 1 rows fetched
17/04/23 17:39:48 INFO: rs.next() is too slow: 3 seconds. 129 rows fetched
17/04/23 17:39:57 INFO: rs.next() is too slow: 8 seconds. 257 rows fetched
17/04/23 17:40:01 INFO: rs.next() is too slow: 3 seconds. 385 rows fetched
17/04/23 17:40:24 INFO: rs.next() is too slow: 22 seconds. 513 rows fetched
17/04/23 17:41:35 INFO: rs.next() is too slow: 71 seconds. 641 rows fetched
17/04/23 17:41:51 INFO: rs.next() is too slow: 15 seconds. 769 rows fetched
17/04/23 17:41:53 INFO: rs.next() is too slow: 2 seconds. 897 rows fetched
17/04/23 17:41:53 INFO: 1000 fetched
17/04/23 17:41:55 INFO: rs.next() is too slow: 1 seconds. 1025 rows fetched
17/04/23 17:41:57 INFO: rs.next() is too slow: 2 seconds. 1153 rows fetched
17/04/23 17:41:59 INFO: rs.next() is too slow: 2 seconds. 1281 rows fetched
17/04/23 17:42:12 INFO: rs.next() is too slow: 12 seconds. 1409 rows fetched
```

위 결과에서 fetched 갯수를 보면 128 이라는 일정한 규칙이 나타납니다. SQLServerResultSet 클래스를 디컴파일해보니 다음과 같이 되어 있습니다.

> this.nFetchSize = 1009 == this.resultSetConcurrency?8:128;

resultSetConcurrency는 무슨 값인지는 모르겠지만 Fetch Size의 기본 값이 128 로 설정되는 부분이 있습니다. 이것을 보고 setFetchSize를 통해 한번에 가져오는 Row의 갯수를 지정해보았습니다.

> rs.setFetchSize(1000);

결과는 다음과 같습니다.  

```
17/04/23 17:44:13 INFO: ResponseBuffering: adaptive
17/04/23 17:44:13 INFO: Start run query
17/04/23 17:44:13 INFO: Finish run query
17/04/23 17:46:44 INFO: rs.next() is too slow: 151 seconds. 1 rows fetched
17/04/23 17:46:44 INFO: 1000 fetched
17/04/23 17:48:19 INFO: rs.next() is too slow: 94 seconds. 1001 rows fetched
17/04/23 17:48:19 INFO: 2000 fetched
```

보시면 실제 executeStatement() 부분은 빨리 실행하고, 1000 건 단위로 fetch 작업 시 오랜 시간에 걸려 데이터를 가져오는 것을 볼 수 있습니다.

## 정말로 느린 것일까?

여기까지 테스트를 진행하고 이런 의문점이 들었습니다. SQLServer가 이렇게 동작하는 것이 이상한 것이 아니라 전체 질의 수행 시간은 동일하지 않을까? 예를 들어

- MySQL의 경우라면 executeStatement()에 100초가 소요되었고 fetch에는 시간이 소요되지 않은 반면
- SQLServer는 executeStatement()에는 시간이 소요되지 않는 반면 fetch의 총합이 100초가 되지 않을까?

이런 가정이라면 사용자 입장에서는 나쁘지 않은 구성입니다. 아직 이 비교는 해보지 못했습니다. 두 데이터베이스의 성능이 다르고 구성이 다르기때문에 BMT 환경이 아닌 실제 운영 환경에서는 비교하기 어렵습니다.

Update: 아래 페이스북 댓글로 @이수열님이 답변을 주셨습니다.

> JDBC 문제는 아니구요  
> Oracle 이나 MSSQL에는 DBMS 자체에 '부분범위처리','전체범위처리' 라는 메카니즘이 있어요.  
>  
>  
>  
> 부분범위처리는 데이타를 끝까지 뒤져서 반환하지 않고 일단 일정량만 검색해서 돌려주고 next 요청이 있을때 그 다음부터 검색해 돌려주는 방식인데,  
> 쿼리문 분석에 따라 반드시 끝까지 뒤져봐야만 할 상황이 아니라면 부분범위처리로 작동합니다.  
>  
> 부분범위처리나 전체범위처리나 끝까지 처리하는 시간은 같다고 보시면 됩니다 ^^

## 마치며

이글의 앞부분에서도 언급했는데 이 글의 목적이 다르게 동작한다는 것과, 증상을 설명하고, 여러분들의 의견을 듣고자 하는 것이라서 SQLServer가 느리다, 아니면 SQLServer의 JDBC가 느리다 라는 결론은 아닙니다. 이 부분에 대해 명쾌하게 설명해주실 있는 분이나 SQLServer 관계자가 보시면 답변 부탁드립니다.

- 다음 maven dependency를 사용해도 동일하게 나타남  
<dependency>  
<groupId>com.microsoft.sqlserver</groupId>  
<artifactId>mssql-jdbc</artifactId>  
<version>6.1.0.jre8</version>  
</dependency>