Btrace로 DBCP의 connection정보를 모니터링 하기

정상혁정상혁

Connection pool을 library로 DBCP를 많이 사용하고 있습니다. DataSouce가 선언되어 있는 설정 파일을 보면 min, max Connection 숫자는 쉽게 알 있지만, 현재 Active 한 것이 몇개 인지등은 실행시간에 쉽게 알아보기가 쉽지가 않죠. 그래서 JMX로 현재 Active한 Connection 수 등을 노출하는, DBCP를 한번 감싼 DataSource를 사용하기도 합니다.

Btrace를 이용하면 비교적 간단하게 DBCP의 속성들을 값들을 확인할 수 있습니다. 이미 실행되고 있는 JVM에도 붙일 수 있으니 설정을 바꾸고 WAS를 재시작하지 않아도 됩니다.

아래와 같이 간단한 소스로도 가능합니다.

import static com.sun.btrace.BTraceUtils.*;
import java.lang.reflect.Field;
import com.sun.btrace.BTraceUtils.Sys;
import com.sun.btrace.annotations.BTrace;
import com.sun.btrace.annotations.OnMethod;
import com.sun.btrace.annotations.Self;

@BTrace
public class DbcpMonitorSimple {

  private static final String DS_CLASS = "org.apache.commons.dbcp.BasicDataSource";

  @OnMethod(clazz = DS_CLASS, method = "getConnection")
  public static void onGetConnection(@Self Object basicDataSource) {
    Field urlField = field(DS_CLASS, "url");
    Object url = get(urlField, basicDataSource);
    print("=====DBCP BasicDataSource info (");
    print(url);
    println(" ) ==========");
    printFields(basicDataSource);
    Field poolField = field(DS_CLASS, "connectionPool");

    Object pool = get(poolField, basicDataSource);
    println("=====connectionPool (GenericObjectPool) info====");
    printFields(pool);
    println("==========");
    Sys.exit(0);
  }
}

DataSource.getConnection 요청이 있을 때 해당 객체를 얻어와서 속성값들을 찍어줍니다.

그리고 필요한 필드만 찍는다던지, 보기좋게 정렬한다던지 하는 작업은 필요에 따라 하면 되겠죠.

jps로 모니터링하고자 하는 JVM의 pid를 확인하고, btrace [pid] DbcpSimpleMonitor.java 로 실행하면 아래와 같이 속성값들을 쭉 찍어줍니다.

>btrace 4288 DbcpMonitor.java


=====DBCP BasicDataSource info (jdbc:hsqldb:file:store;shutdown=true ) ========

{defaultAutoCommit=true, defaultReadOnly=null, defaultTransactionIsolation=-1, d

efaultCatalog=null, driverClassName=org.hsqldb.jdbcDriver, driverClassLoader=nul

l, maxActive=8, maxIdle=8, minIdle=0, initialSize=0, maxWait=-1, poolPreparedSta

tements=false, maxOpenPreparedStatements=-1, testOnBorrow=false, testOnReturn=fa

lse, timeBetweenEvictionRunsMillis=-1, numTestsPerEvictionRun=3, minEvictableIdl

eTimeMillis=1800000, testWhileIdle=false, password=, url=jdbc:hsqldb:file:store;

shutdown=true, username=sa, validationQuery=null, validationQueryTimeout=-1, con

nectionInitSqls=null, accessToUnderlyingConnectionAllowed=false, restartNeeded=t

rue, connectionPool=org.apache.commons.pool.impl.GenericObjectPool@1f31079, conn

ectionProperties={user=sa, password=}, dataSource=org.apache.commons.dbcp.Poolin

gDataSource@be8958, logWriter=java.io.PrintWriter@12b1ff9, abandonedConfig=null,

 closed=false, }

===== number of Active : 0

==========

FIeld 객체를 얻어올 때 field(String,String)을 쓰면 static 필드초기화나 @OnMethod 메소드가 붙지 않은 메소드에서는 객체가 얻어지지 않는 에러가 있었습니다.

인터넷을 찾아보니 아래와 같이 비슷한 현상을 겪은 사람이 있었습니다.

http://kenai.com/projects/btrace/forums/forum/topics/1366-Drilling-into-a-method-argument-s-properties

결국 @OnMethod 가 붙지 않는 메소드에서 호출을 할 때는 field(classof(obj), "fieldName") 과 같이 피해가는 방법을 썼습니다. 되도록 메소드에서 매번 호출할 필요가 없는 부분은 static 초기화를 시킬 수 있었으면 하는데, static 초기화로는 하는 것도 잘 되지 않았습니다. 직접 field(BasicDataSource.class, "fieldName)으로 를 참조하기는 것도 잘 안 되었고, field(String,String)으로는 참조가 안 되었습니다. 이것만 아니면 좀 더 최적된 호출을 할 수 있었을 것 같습니다.

첨부한 파일들은 아래와 같은 다소 다른 방식이나 출력형식으로 택했습니다.

  • DbcpMonitorSimple.java : BasicDataSource.getConnection이 한번 호출될 때 BasicDataSource의 모든 정보와 BasicDataSource.connetionPool의 정보를 출력

  • DbcpMonitor.java : 이벤트 방식은 1과 같고, BasicDataSource의 모든 필드와 BasicDataSource.connetionPool에서 _numActive 값만을 보여줌

  • DbcpActiveConnectionMonitor.java : 여러 개의 Datasource의 Active connection 갯수를 구할 때 사용. getConnection에서 URL별로 active connection 갯수를 저장해 두었다가, Btrace에서 이벤트를 날리면 출력을 해주고 종료

첨부한 스크립트 중 1,2번은 getConnection이 한번 호출되고 나면 스크립트를 종료하는 구조라서 큰 부하는 없겠지만, 증가 추이 등의 통계 정보를 쌓는기능 등이 필요하다면 Field poolField = field(DS_CLASS, "connectionPool"); 같은 부분도 중복호출되지 않게 하는 처리가 필요합니다.

소스는 gist에 올렸습니다. ( https://gist.github.com/1246239 )

Kent Beck과의 인터뷰 중에서..

정상혁정상혁

2010년 9월에 Kent Beck과의 인터뷰가 SE-Radio 사이트에 올라왔었습니다.

http://www.se-radio.net/2010/09/episode-167-the-history-of-junit-and-the-future-of-testing-with-kent-beck/

이 인터뷰 중에 아래 내용이 가장 인상 깊었고, 몇달이 지나서도 기억에 남아있습니다.

19분 경에 나오는 내용입니다.

받아쓴 내용

Martin(사회자):

Do you think you’ve convinced most of people you talk to?

Kent Beck :

I don’t try to convince people any more.I think I spent probably 10 years really trying to convince people TDD, pair programming, you should do this, you should do that and I don’t do that any more.

I am always working to improve my own practice, I am eager to share what I learn and I try and listen and understand what other people learned and their experiences as well. So I don’t like …​ I don’t really keep score by how many people do TDD.

If the practice of software development is improving overall, then I think that’s a great thing, If I have some small influence on that, then I think that’s a great thing too.

번역

마틴(사회자)

그동안 이야기한 사람들을 대부분 설득했다고 생각합니까?

켄트벡 :

저는 더 이상 사람들을 설득하려 하지 않습니다. 저는 거의 10년동안 사람들에게 TDD를 꼭해라, 짝프로그래밍을 꼭 해라고 설득하려고 애써왔지만, 더 이상 그렇게 하지 않습니다.

전 항상 제가 수행하는 방식을 개선하려고 일하고, 제가 시도하고 배운 것을 공유하려고 노력합니다. 다른 사람이 배운 것과 경험도 듣고 이해하려 하구요. 그래서 전 얼마나 많은 사람들이 TDD를 하는지를 가지고 점수를 매기지는 않습니다.

소프트웨어를 개발하는 방식이 전반적으로 나아진다면 전 그걸 대단한 일이라고 생각하고, 만약 제가 거기에 약간의 영향이라도 끼친다면 역시나 대단한 일이라고 생각합니다.

Spring AOP의 Aspect에서 order 값에 따른 적용순서 확인해보기

정상혁정상혁

Spring AOP에서 동일한 target클래스에 결합되는 Aspect의 우선순위는 Ordered 인터페이스를 구현하거나 @Order 애노테이션으로 지정합니다.

아래와 같은 방식입니다.

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.springframework.core.annotation.Order;

@Aspect
@Order(1)
public class OrderOneAspect {
    @Before("execution(void *.run())")
    public void printOrder(JoinPoint jp){
        System.out.println("order 1");
    }
}
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.springframework.core.Ordered;



@Aspect
public class OrderTwoAspect implements Ordered{
    @Before("execution(void *.run())")
    public void printOrder(JoinPoint jp){
        System.out.println("order 2");
    }
    public int getOrder() {
        return 2;
    }
}

OrderOneAspect 은 애노테이션으로, OrderTwoAspect은 인터페이스로 order 값을 선언했습니다.

Ordered 인터페이스의 javadoc에 보면 order의 숫자 값이 작을수록 우선 순위가 높다고 적혀 있습니다.

The actual order can be interpreted as prioritization, with the first object (with the lowest order value) having the highest priority.

그렇다면 AOP에서는 여러개의 Aspect를 엮을 때 order값을 낮게 선언한 Aspect가 먼저 실행될까요?

한번 테스트코드를 짜봤습니다. 위의 OrderOneAspect , OrderTwoAspect와 함께, 각각 0과 -1의 order를 가지는 Aspect를 더 추가했습니다.

@Aspect
@Order(0)
public class OrderZeroAspect {
    @Before("execution(void *.run())")
    public void printOrder(JoinPoint jp){
        System.out.println("order 0");
    }
}

@Aspect
@Order(-1)
public class OrderMinusOneAspect {
    @Before("execution(void *.run())")
    public void printOrder(JoinPoint jp){
        System.out.println("order -1");
    }
}

그리고 Target클래스와 Proxy를 만들어줄 설정을 javaConfig를 이용해서 추가합니다.

public class MainBeans {
    @Bean
    public ProxyConfig proxyCreator(){
        return new AspectJAwareAdvisorAutoProxyCreator();
    }
    @Bean
    public Runnable main(){
        return new Runnable(){
            public void run() {
                System.out.println("target executed");
            }
        };
    }
}

Aspect는 모두 "before" Advice로 그 Aspect의 order 값을 찍도록했고, 적용대상인 클래스는 단순히 "target executed"를 출력합니다. 출력창에 찍힌 내용을 보면 어떤 순서로 Aspect가 적용되는지 보입니다.

모두 ApplicationContext에 등록해서 Target클래스를 출력하는 테스트 코드를 만들었습니다.

public class AspectOrderTest {
    @Test
    public void checkOrder() throws Exception {
        GenericApplicationContext  context =
            new AnnotationConfigApplicationContext(
                OrderZeroAspect.class,
                OrderMinusOneAspect.class,
                OrderTwoAspect.class,
                OrderOneAspect.class,
                MainBeans.class);
        Runnable printer = context.getBean(Runnable.class);
        printer.run();
    }
}

출력 결과는 아래와 같습니다.

order 2 order 1 order 0 order -1 target executed

Order의 숫자가 큰 값이 먼저 나옵니다. 큰 Order 값인, 낮은 우선 순위인 Aspect가 먼저 실행되었다는 결과입니다. 제가 처음에 매뉴얼만 보고 이해한 의미와는 반대의 결과였습니다. 제가 설정을 잘못한 부분이 있는지도 모르겠지만, 이 결과만을 해석을 해보겠습니다.

Aspect에서 우선순위가 높다는 의미는 '안쪽의 proxy가 된다.'는 의미입니다. 즉, Proxy를 만들 때 Order값이 작은, 우선 순위가 높은 Aspect부터 먼저 Proxy를 만들고, 그 뒤에 다음 우선순위의 proxy들을 차례로 입혀갑니다. 그러니 'before' 나 'Around’Advice라면 가장 바깥 쪽에 Proxy로 입혀진 , order값이 큰, 우선순위가 낮은 Aspect의 코드가 먼저 실행됩니다.

정리하면, Order값 숫자가 작을수록 우선 순위가 높아지고, 우선 적용되어서 더 안 쪽에서 감싸지는 proxy가 되어서 타겟 Object의 코드와 붙어있는 Apspect가 된다는 의미입니다. 즉, Aspect 설정에서 order값의 숫자가 클 수록 target객체에서 더 멀어지는 바깥 쪽의 Proxy로 결합됩니다.