이전장(aridom.tistory.com/72)에서 Mybatis Plugins라는것을 알아봤다. 이번에는 Mybatis Plugins 중 하나인 StatementHandler를 이용하면서 발생된 이슈와 이놈이 무슨역할을 하는지 알아보도록 하자.
StatementHandler
Mybatis3에 구현된 StatementHandler 인터페이스는 아래와 같다.
package org.apache.ibatis.executor.statement;
import java.sql.Connection;
import java.sql.SQLException;
import java.sql.Statement;
import java.util.List;
import org.apache.ibatis.cursor.Cursor;
import org.apache.ibatis.executor.parameter.ParameterHandler;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.session.ResultHandler;
/**
* @author Clinton Begin
*/
public interface StatementHandler {
Statement prepare(Connection connection, Integer transactionTimeout)
throws SQLException;
void parameterize(Statement statement)
throws SQLException;
void batch(Statement statement)
throws SQLException;
int update(Statement statement)
throws SQLException;
<E> List<E> query(Statement statement, ResultHandler resultHandler)
throws SQLException;
<E> Cursor<E> queryCursor(Statement statement)
throws SQLException;
BoundSql getBoundSql();
ParameterHandler getParameterHandler();
}우리가 눈여겨 볼 필요가 있는 메소드는 4개(prepare, parameterize, batch, update)가 있다.
PrepareStatementHandler는 파라매터가 존재하는 SQL문을 전처리할 때 주로 Intercept하는 동작을 수행한다.
prepare method
prepare 메서드는 추상 클래스인 BaseStatementHandler에 구현되어 있다.
결과적으로 Statement 타입으로 값을 반환하는데 이때 요청하는 메서드는 추상 메서드인 instantiateStatement를 호출한다.
@Override
public Statement prepare(Connection connection, Integer transactionTimeout) throws SQLException {
ErrorContext.instance().sql(boundSql.getSql());
Statement statement = null;
try {
statement = instantiateStatement(connection);
setStatementTimeout(statement, transactionTimeout);
setFetchSize(statement);
return statement;
} catch (SQLException e) {
closeStatement(statement);
throw e;
} catch (Exception e) {
closeStatement(statement);
throw new ExecutorException("Error preparing statement. Cause: " + e, e);
}
}
instantiateStatement메소드는 BaseStatementHandler를 구현한 상속받은 PreparedStatementHandler에 구현되어 있다.
매개변수가 설정되지 않은 sql문을 추출 후 사전 컴파일 작업을 수행한다.
매개 변수들인 keyColumnNames 배열과 전처리 중인 sql문을 prepareStatement로 넘기는 모습을 볼 수 있다.
@Override
protected Statement instantiateStatement(Connection connection) throws SQLException {
String sql = boundSql.getSql();
if (mappedStatement.getKeyGenerator() instanceof Jdbc3KeyGenerator) {
String[] keyColumnNames = mappedStatement.getKeyColumns();
if (keyColumnNames == null) {
return connection.prepareStatement(sql, PreparedStatement.RETURN_GENERATED_KEYS);
} else {
return connection.prepareStatement(sql, keyColumnNames);
}
} else if (mappedStatement.getResultSetType() == ResultSetType.DEFAULT) {
return connection.prepareStatement(sql);
} else {
return connection.prepareStatement(sql, mappedStatement.getResultSetType().getValue(), ResultSet.CONCUR_READ_ONLY);
}
}parameterize method
위에서 prepare을 했으니 이번에는 파라매터를 설정하는 작업은 parameterize 메서드가 담당한다.
해당 메서드는 PreparedStatementHandler 클래스에 구현되어있으며 setParameters 메서드를 통해 statement에 파라매터를 설정하는 작업을 수행한다.
@Override
public void parameterize(Statement statement) throws SQLException {
parameterHandler.setParameters((PreparedStatement) statement);
}update method
SQL에 대해 전처리 작업과 파라매터 설정이 끝났다면 이제 쿼리를 수행할 차례다.
update 메서드는 PrepareStatement를 수행 후 Primary Key를 생성하는 작업을 수행한다.
단, 삽입되는 Primary key는 Automatically 하게 되어있을 때 가능하다.
얘 또한 PreparedStatementHandler에 구현되어 있다.
@Override
public int update(Statement statement) throws SQLException {
PreparedStatement ps = (PreparedStatement) statement;
ps.execute();
int rows = ps.getUpdateCount();
Object parameterObject = boundSql.getParameterObject();
KeyGenerator keyGenerator = mappedStatement.getKeyGenerator();
keyGenerator.processAfter(executor, mappedStatement, ps, parameterObject);
return rows;
}batch method
batch 메서드는 말 그대로 대량 처리 작업을 수행한다.
@Override
public void batch(Statement statement) throws SQLException {
PreparedStatement ps = (PreparedStatement) statement;
ps.addBatch();
}Batch Type수행 시 StatementHandler의 prepare 메서드 이슈
회사에서 사용하는 프로그램은 StatementHandler의 prepare 메서드를 인터셉터하여 별도로 전처리 작업을 수행하며, SQL문을 log4j에 기록하게 되어있다. 며칠 전 회사에서 다음과 같은 요청사항이 있었다.
쿼리를 처리할 때 ExecutorType이 Batch인 작업을 수행하면 제일 처음에 수행한 Insert문만 로그로 찍히고 그 뒤에는 정상적으로 찍히지 않는다.
이게 무슨 소리인지 이해하기위해 직접 Batch 타입으로 수행하는 코드를 작성해서 돌려보니 아래와 같이 출력되고 있었다. 실제로 Mybatis Intercept 하는 구간에 logger가 처음에 수행된 쿼리만 찍혀있고 그냥 넘어간 것이다.
[10:02:31.495] [INFO] com.xxx.xxx.xxx.xxx.xxx [intercept:xx] - INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
1,
'XXX',
29,
'Programmer',
'A'
)
[10:02:31.505] [INFO] jdbc.sqltiming [sqlTimingOccurred:373] - batching 2 statements:
1: INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
1,
'XXX',
29,
'Programmer',
'A'
)
2: INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
2,
'XXX2',
29,
'Programmer2',
'B'
)
{executed in 8 msec}
분명 Insert 작업은 2번 발생된 건 jdbc.sqltiming을 통해 확인은 되지만 Intercept의 log4j에는 1개만 출력되고 있다.
한창 자료를 찾다 Mybatis-3의 공식 Github에서 아래와 같은 이슈를 볼 수 있었다.
In a batch operation, StatementHandler#prepare() is called just once and the created PreparedStatement is reused for all parameters, so the log output is expected.
(배치 작업에서 StatementHandler의 prepare()는 단 한 번만 호출되며, PrepareStatement는 모든 매개변수에 재사용됩니다.)
If you apply a your interceptor to the StatementHandler#parameterize method instead of StatementHandler#prepare, you may be able to expected result.
(만약 StatementHandler의 prepare 대신 parameterize 타입으로 인터셉터를 하면 정상적으로 적용될 것입니다.)
참고 : github.com/mybatis/mybatis-3/issues/1753
즉 prepare 작업은 한 번만 호출되고 parameterize 작업에서 재사용되기 때문에 로그가 한 번 찍혔던 것이다.
우리는 parameterize 작업을 하기 전 전처리 작업을 해줘야 했기에 아래와 같이 2개의 메서드 타입을 추가했다.
@Intercepts({
@Signature(type = StatementHandler.class, method = "prepare", args = { Connection.class, Integer.class }),
@Signature(type = StatementHandler.class, method = "parameterize", args = { Statement.class })
})
public class XXIntercept implements Interceptor {
...
}
주의해야 할 점은 단순히 이렇게 하고 동작시키면 로그가 2번 찍히게 된다.
prepare 하는 과정과 parameterize 작업을 거쳐가기 때문이다.
따라서 아래와 같이 methodType을 찾아 parameterize일 때만 로그를 남기도록 했다.
...
String methodType = invocation.getMethod().getName();
if (methodType.equals("parameterize")) {
logger.info("{}", bindSql);
}
...
그 결과 아래와 같이 정상적으로 결과가 출력된 걸 확인할 수 있었다.
[09:58:09.671] [INFO] com.xxx.xxx.xxx.xxx.xxx [intercept:xx] - INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
1,
'XXX',
29,
'Programmer',
'A'
)
[09:58:09.674] [INFO] com.xxx.xxx.xxx.xxx.xxx [intercept:xx] - INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
2,
'XXX2',
29,
'Programmer2',
'B'
)
[09:58:09.687] [INFO] jdbc.sqltiming [sqlTimingOccurred:373] - batching 2 statements:
1: INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
1,
'XXX',
29,
'Programmer',
'A'
)
2: INSERT INTO TEST_USERINFO
(
USER_INDEX,
USER_NAME,
USER_AGE,
USER_JOB,
USER_TYPE
)
VALUES
(
2,
'XXX2',
29,
'Programmer2',
'B'
)
{executed in 11 msec}'Spring > 참고사항' 카테고리의 다른 글
| Mybatis Plugins (0) | 2021.02.17 |
|---|