오늘은 어디로 갈까...

Proxy를 이용해서 sql 출력해보기 본문

낙서

Proxy를 이용해서 sql 출력해보기

剛宇 2009. 6. 1. 10:30
 요즘 프로그래밍 삼매경에 빠져있다 보니, 블로그를 소홀히 하는것같아서 의무적(?)으로 몇글자 적어보겠다. 사실 삼매경이라기 보다는, 능력 부족으로 인해서 허우적거리고 있다는게 맞는거 같지만 말이다. ^^;

 JDBC를 이용해서 데이터를 처리할때, 실행 쿼리를 로그로 출력했으면 하는 마음을 가졌던 적이 있을것이다.
 Connection을 가져오고, Statement를 생성해서 실행하는 원초적(?)인 방법을 사용하는곳에서는, 로그 출력하는 부분을 매 코드마다 추가해 줄수도 있지만, 너무 귀찮지 아니한가. 그래서 좀더 쉬운 방법을 연구해보자.
 본인같은 무식한 성격의 소유자는 java.sql.Connection, java.sql.PreparedStatement 등을 상속 받아 구현한 Wrapper Class를 만든다음, 원래 Connection, PreparedStatement  구현 객체를 넘겨받아 호출만 대행하면서 로그를 남기는 방법을 사용할것이다.
 그런데, 그 많은(?) 메소드를 구현하기도 귀찮으니 좀더 우아한(?) 방법을 사용하도록 하자.
 그건 바로 java.lang.reflect.Proxy를 이용하는 것이다.
 Proxy를 이용해면, 필요한 몇몇 메소드가 실행될때만 로그를 출력하게  아주 간단히 구현할 수 있다. 이 Proxy의 제약사항은 대상 객체가 인터페이스를 구현해야한다는것인데, 우리가 사용할 객체들은 모두 인터페이스를 가지고 있으므로 아무 문제 없이 사용할 수 있다.

 1. ConnectionLogProxy 만들기
package kr.kangwoo.util.sql.logging;

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;
import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.Statement;

import kr.kangwoo.util.BeanUtils;
import kr.kangwoo.util.logging.Logger;
import kr.kangwoo.util.logging.LoggerFactory;

public class ConnectionLogProxy extends BaseLogProxy implements InvocationHandler {

	
	private Logger logger = LoggerFactory.getLogger(Connection.class);
	
	private int connectionId;
	private Connection connection;
	private int nextStatementId;
	
	
	private ConnectionLogProxy(Connection connection) {
		this.connectionId = System.identityHashCode(connection);
		this.connection = connection;
		if (logger.isDebugEnabled()) {
			logger.debug(getIdentify(connectionId) + " Created " + connection);
		}
	}

	public Object invoke(Object proxy, Method method, Object[] args)
			throws Throwable {
		try {
			if ("prepareStatement".equals(method.getName())) {
				PreparedStatement pstmt = (PreparedStatement)method.invoke(connection, args);
				pstmt = PreparedStatementLogProxy.newInstance(connectionId, getNextStatementId(), pstmt, (String) args[0]);
				return pstmt;
			} else if("createStatement".equals(method.getName())) {
				Statement stmt = (Statement)method.invoke(connection, args);
				stmt = StatementLogProxy.newInstance(connectionId, getNextStatementId(), stmt);
				return stmt;
			} else if ("commit".equals(method.getName())) {
				if (logger.isDebugEnabled()) {
					logger.debug(getIdentify(connectionId) + " Commited " + connection);
				}
			} else if ("rollback".equals(method.getName())) {
				if (logger.isDebugEnabled()) {
					logger.debug(getIdentify(connectionId) + " Rollbacked " + connection);
				}
			} else if ("close".equals(method.getName())) {
				if (logger.isDebugEnabled()) {
					logger.debug(getIdentify(connectionId) + " Closed " + connection);
				}
			}
			return method.invoke(connection, args);
		} catch(Throwable t) {
			throw BeanUtils.unwrapThrowable(t);
		}
	}

	private int getNextStatementId() {
		return nextStatementId++;
	}
	
	public Connection getConnection() {
		return connection;
	}
	
	public static Connection newInstance(Connection connection) {
		InvocationHandler handler = new ConnectionLogProxy(connection);
		return (Connection)Proxy.newProxyInstance(Connection.class.getClassLoader(), new Class[]{Connection.class}, handler);
	}
}

ProxyInstance를 만들려면, InvocationHandler를 구현한 Handler를 만든다음, Proxy.newProxyInstance(ClassLoader, Class[] InvocationHandler)를 이용하면 된다. ConnectionLogProxy 같은 경우 아래 부분이 되겠다.
	public static Connection newInstance(Connection connection) {
		InvocationHandler handler = new ConnectionLogProxy(connection);
		return (Connection)Proxy.newProxyInstance(Connection.class.getClassLoader(), new Class[]{Connection.class}, handler);
	}


대상 인터페이스의 메소드가 실행될때마다. Object invoke(Object proxy, Method method, Object[] args) 메소드가 호출된다. 이 부분에서 필요한 처리를 하면 되는것이다. "prepareStatement" 란 이름을 가진 메소드를 만나면, 원래의 PreparedStatement가 아닌, 로그 출력을 위해 재구현한 PreparedStatement 을 반환해주는것을 알 수 있다.
			if ("prepareStatement".equals(method.getName())) {
				PreparedStatement pstmt = (PreparedStatement)method.invoke(connection, args);
				pstmt = PreparedStatementLogProxy.newInstance(connectionId, getNextStatementId(), pstmt, (String) args[0]);
				return pstmt;
			}


그리고 마지막 부분에 throw BeanUtils.unwrapThrowable(t); 부분이 있는데, 이건 중요한것은 아니지만, 처리중 에러가 발생했을 경우 UndeclaredThrowableException, InvocationTargetException, 을 제거해주는역할을 하는 것이다. 즉, 에러가 발생했을지 불필요한 정보를 없애버리는것이다.
Exception in thread "main" java.lang.reflect.UndeclaredThrowableException
	at $Proxy7.execute(Unknown Source)
	at kr.kangwoo.damo.support.execute.SimpleQueryExecutor.executeUpdate(SimpleQueryExecutor.java:51)
	at kr.kangwoo.damo.Session.executeUpdate(Session.java:159)
	at kr.kangwoo.damo.delegate.QueryExecutorDelegate.executeUpdate(QueryExecutorDelegate.java:24)
	at kr.kangwoo.damo.PersistenceManagerImpl.executeUpdate(PersistenceManagerImpl.java:103)
	at kr.kangwoo.damo.PersistenceManagerImpl.insert(PersistenceManagerImpl.java:108)
	at kr.kangwoo.damo.Test.main(Test.java:40)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at kr.kangwoo.util.sql.logging.PreparedStatementLogProxy.invoke(PreparedStatementLogProxy.java:132)
	... 7 more
Caused by: java.sql.SQLException: ORA-00911: 문자가 부적합합니다

	at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
	at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:331)
	at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:288)
	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:743)
	at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:216)
	at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:955)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1168)
	at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3285)
	at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3390)
	... 12 more

이랬던 에러가~~~ 아래처럼 바뀐다는것인데, 뭐 무시해도 상관없다. 
Exception in thread "main" java.sql.SQLException: ORA-00911: 문자가 부적합합니다

	at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
	at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:331)
	at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:288)
	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:743)
	at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:216)
	at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:955)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1168)
	at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3285)
	at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3390)
	... 12 more


	public static Throwable unwrapThrowable(Throwable throwable) {
		Throwable t = throwable;
		while (true) {
			if (t instanceof UndeclaredThrowableException) {
				t = ((UndeclaredThrowableException)t).getUndeclaredThrowable();
			} else if (t instanceof InvocationTargetException) {
				t = ((InvocationTargetException)t).getTargetException();
			} else {
				return t;
			}
		}
	}


2. PreparedStatementLogProxy 만들기
package kr.kangwoo.util.sql.logging;

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;
import java.sql.CallableStatement;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.util.HashSet;
import java.util.LinkedHashMap;
import java.util.Map;
import java.util.Set;

import kr.kangwoo.util.BeanUtils;
import kr.kangwoo.util.StringUtils;
import kr.kangwoo.util.SystemUtils;
import kr.kangwoo.util.logging.Logger;
import kr.kangwoo.util.logging.LoggerFactory;

public class PreparedStatementLogProxy extends BaseLogProxy implements InvocationHandler {

	private static final Set<String> EXECUTE_METHOD_NAMES = new HashSet<String>();
	private static final Set<String> SET_METHOD_NAMES = new HashSet<String>();
	
	static {
		EXECUTE_METHOD_NAMES.add("execute");
		EXECUTE_METHOD_NAMES.add("executeUpdate");
		EXECUTE_METHOD_NAMES.add("executeQuery");
		
		SET_METHOD_NAMES.add("setNull");
		SET_METHOD_NAMES.add("setBoolean");
		SET_METHOD_NAMES.add("setByte");
		SET_METHOD_NAMES.add("setShort");
		SET_METHOD_NAMES.add("setInt");
		SET_METHOD_NAMES.add("setLong");
		SET_METHOD_NAMES.add("setFloat");
		SET_METHOD_NAMES.add("setDouble");
		SET_METHOD_NAMES.add("setBigDecimal");
		SET_METHOD_NAMES.add("setString");
		SET_METHOD_NAMES.add("setBytes");
		SET_METHOD_NAMES.add("setDate");
		SET_METHOD_NAMES.add("setTime");
		SET_METHOD_NAMES.add("setTimestamp");
		SET_METHOD_NAMES.add("setAsciiStream");
		SET_METHOD_NAMES.add("setBinaryStream");
		SET_METHOD_NAMES.add("setObject");
		// JDBC 2.0
		SET_METHOD_NAMES.add("setCharacterStream");
		SET_METHOD_NAMES.add("setRef");
		SET_METHOD_NAMES.add("setBlob");
		SET_METHOD_NAMES.add("setClob");
		// JDBC 3.0
		SET_METHOD_NAMES.add("setURL");
	}
	
	private Logger logger = LoggerFactory.getLogger(PreparedStatement.class);
	
	private int connectionId;
	private int statementId;
	private int nextResultSetId;
	private PreparedStatement pstmt;
	private String sql;
	
	private Map<Object, Object> columnMap = new LinkedHashMap<Object, Object>();
	private int batchTotalCount;
	private int batchCount;
	
	private PreparedStatementLogProxy(int connectionId, int statementId, PreparedStatement pstmt, String sql) {
		this.connectionId = connectionId;
		this.statementId = statementId;
		this.pstmt = pstmt;
		this.sql = sql;
		if (logger.isDebugEnabled()) {
			logger.debug(getIdentify(connectionId, statementId) + " Created " + pstmt + " : " + sql);
		}
	}
	
	public Object invoke(Object proxy, Method method, Object[] args)
			throws Throwable {
		try {
			if (EXECUTE_METHOD_NAMES.contains(method.getName())) {
				if (logger.isDebugEnabled()) {
					StringBuilder msg = new StringBuilder();
					msg.append(getIdentify(connectionId, statementId)).append(" Executing ").append(pstmt).append(SystemUtils.LINE_SEPARATOR);
					msg.append(sql);
					int keyLen = String.valueOf(columnMap.size()).length();
					for (Object key : columnMap.keySet()) {
						msg.append(SystemUtils.LINE_SEPARATOR);
						msg.append("[").append(StringUtils.leftPad(key.toString(), keyLen, "0")).append("] ").append(columnMap.get(key));
					}
					logger.debug(msg.toString());
					columnMap.clear();
				}
				if ("executeQuery".equals(method.getName())) {
					ResultSet rs = (ResultSet) method.invoke(pstmt, args);
					if (rs != null) {
						return ResultSetLogProxy.newInstance(connectionId, statementId, getNextResultSetId(), rs);
					} else {
						return null;
					}
				}
			} else if ("executeBatch".contains(method.getName())) {
				logger.debug(getIdentify(connectionId, statementId) + " Executing Batch " + pstmt + " : COUNT = " + batchCount + ", TOTAL = " + batchTotalCount);
				batchCount = 0;
			} else if ("addBatch".contains(method.getName())) {
				batchCount++;
				batchTotalCount++;
			} else if (SET_METHOD_NAMES.contains(method.getName())) {
				if ("setNull".equals(method.getName())) {
					columnMap.put(args[0], null);
				} else {
					columnMap.put(args[0], args[1]);
				}
			} else if ("getResultSet".equals(method.getName())) {
				ResultSet rs = (ResultSet) method.invoke(pstmt, args);
				if (rs != null) {
					return ResultSetLogProxy.newInstance(connectionId, statementId, getNextResultSetId(), rs);
				} else {
					return null;
				}
			} else if ("equals".equals(method.getName())) {
				Object obj = args[0];
				if (obj instanceof Proxy) {
					return new Boolean(proxy == obj);
				}
				return Boolean.FALSE;
			} else if ("hashCode".equals(method.getName())) {
				return new Integer(proxy.hashCode());
			} else if ("close".equals(method.getName())) {
				if (logger.isDebugEnabled()) {
					logger.debug(getIdentify(connectionId, statementId) + " Closed " + pstmt);
				}
			}
			return method.invoke(pstmt, args);
		} catch(Throwable t) {
			throw BeanUtils.unwrapThrowable(t);
		}
	}
	
	private int getNextResultSetId() {
		return nextResultSetId++;
	}
	
	public PreparedStatement getPreparedStatement() {
		return pstmt;
	}
	
	public static PreparedStatement newInstance(int connectionId, int statementId, PreparedStatement pstmt, String sql) {
		InvocationHandler handler = new PreparedStatementLogProxy(connectionId, statementId, pstmt, sql);
		return (PreparedStatement)Proxy.newProxyInstance(PreparedStatement.class.getClassLoader(), new Class[]{PreparedStatement.class, CallableStatement.class}, handler);
	}
}

- 코드가 복잡(?)해 보이지만 사실은 별거 없다. 파라메터 값이 설정될때, 그 값을 저장했다가 실행할때 로그로 출력해분이 있고, ResultSet을 반환할때 또다른(?) ResultSet을 반환해주는 정도뿐...
 - 구조에 따라 다르겠지만, 본인이 만든(?) DAMO에서는 같은 sql일 경우 PreparedStatement을 재사용하게 되어 있었다. 그런데, 이 PreparedStatementLogProxy를 사용할 경우 가끔(?) 예상치 못한 에러가 발생했는데, 그 이유가 hash, equals를 구현해주지 않아서 논리적 오류가 발생했던것이다. ㅠㅠ


3. 사용하기
 - 나사가 많이 빠져서, 위의 소스만으로는 실행이 안될것이다. 중요한 나사들이 아니니 알아서 잘 구현보도록 하자. ^^;
	Connection conn = null;
	conn = ...
	if (enableLog) {
		conn = ConnectionLogProxy.newInstance(conn);
	}
	..

 - 대충 구현하면 아래와 같은 느낌으로 출력이 될것이다.
[conn@134a7d8] Created oracle.jdbc.driver.T4CConnection@134a7d8
[conn@134a7d8,stmt-0] Created oracle.jdbc.driver.T4CPreparedStatement@c1f10e : INSERT INTO MAIL (MAIL_NO, TEMPLATE_ID, STATUS_CODE, TO_ADDRESS, TO_NAME, FROM_ADDRESS, FROM_NAME, SUBJECT_DATA, COTENT_DATA, SENT_BY, SENT_DATE, CREATED_BY, CREATION_DATE, UPDATED_BY, UPDATED_DATE) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
[conn@134a7d8,stmt-0] Executing oracle.jdbc.driver.T4CPreparedStatement@c1f10e
INSERT INTO MAIL (MAIL_NO, TEMPLATE_ID, STATUS_CODE, TO_ADDRESS, TO_NAME, FROM_ADDRESS, FROM_NAME, SUBJECT_DATA, COTENT_DATA, SENT_BY, SENT_DATE, CREATED_BY, CREATION_DATE, UPDATED_BY, UPDATED_DATE) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
[01] 100
[02] 002
[03] 00
[04] goodnom@kangwoo.kr
[05] 착한놈
[06] badnom@kangwoo.kr
[07] 나쁜놈
[08] null
[09] My Name Is Tester
[10] null
[11] null
[12] Tester
[13] 2009-05-31 13:21:23.531
[14] null
[15] null
 

*. 뱀다리.
 - 개발 모드에서는 sql 로그를 마구~~ 뿌려줘도 상관없지만, 운영에서는 그렇지 못하죠. 그런데, 운영에서, 에러가 발생할 경우, 에러 로그는 찍는데, sql을 안찍어서 애를 먹는경우가 있는데, 위의 코드를 살짝만 수정하면, 에러가 발생했을때만 sql을 찍게 변경하는것도 가능하죠~~~~~~ 믿거나~ 말거나~~
 - 공개SW공모전을 하네요.(http://oss.or.kr/notice/popup_view.html?num=256) 참가해보고 싶지만, 만들만한게.. 흠흠.

'낙서' Related Articles more