Hibernate 4.3 Statement Warning 문제

Naver Pinpoint를 테스트하기 위해 프로젝트의 트랜잭션을 확인하던 중 이상한 것을 발견했다.

Hibernate 4.3 Statement Warning
Naver Pinpoint CallStack Sample

코드 상에 없는 SHOW WARNINGS 라는 질의가 실행된 것이다.

디버그 모드로 원인을 찾아 보니 Hibernate 4.2 버전과는 다르게 Hibernate 4.3에서는 Statement 를 닫을 때 SqlExceptionHelper#logAndClearWarnings(Statement) 를 호출하도록 되어 있다
(4.2에서도 해당 메소드는 있지만 임시 테이블을 만드는 작업을 할 때만 호출한다).

해당 메소드를 보면 다음과 같다:

@SuppressWarnings({"ThrowableResultOfMethodCallIgnored"})
public void handleAndClearWarnings(
 Statement statement,
 WarningHandler handler) {
 // See HHH-9174. Statement#getWarnings can be an expensive call for many JDBC libs. Don't do it unless
 // the log level would actually allow a warning to be logged.
 if (LOG.isEnabled(Level.WARN)) {
 try {
 walkWarnings( statement.getWarnings(), handler );
 }
 catch (SQLException sqlException) {
 // workaround for WebLogic
 LOG.debug( "could not log warnings", sqlException );
 }
 }
 try {
 // Sybase fail if we don't do that, sigh...
 statement.clearWarnings();
 }
 catch (SQLException sqle) {
 LOG.debug( "could not clear warnings", sqle );
 }
}

로그 레벨이 WARN이 가능한 경우 walkWarnings(…)이 실행되고 이것은 Statement#getWarnings()를 호출하는데, MySQL의 경우 실질적으로 SQLError#convertShowWarningsToSQLWarnings(…) 이 실행된다. 이 메소드의 내부에는 다음과 같은 코드가 있어서 SHOW WARNINGS 질의를 실행한다.

/*
 * +---------+------+---------------------------------------------+ |
 * Level | Code | Message |
 * +---------+------+---------------------------------------------+ |
 * Warning | 1265 | Data truncated for column 'field1' at row 1 |
 * +---------+------+---------------------------------------------+
 */
warnRs = stmt.executeQuery("SHOW WARNINGS");

개발 및 CI 환경에서는 도움이 될 수 있겠지만 production 환경에서는 모든 Statement 를 닫을 때마다 문제가 있는지 확인하는 SQL이 실행되는 것은 바람직하지 않다.

production 환경에서 이것이 실행되지 않게 하려면 다음과 같이 로그 레벨을 ERROR로 올린다.

<log4j ...>
  <logger name="org.hibernate.engine.jdbc.spi.SqlExceptionHelper">
    <level value="ERROR" />
  </logger>
</log4j>