Heading 테스트 환경#

  1. jdk1.6.0_23
  2. 프로파일링 옵션 : -Xrunhprof:cpu=samples,file=d:/cpu1.txt,depth=3
    • runhprof 옵션은 jdk 가 제공하는 기본 프로파일링 기능으로 자세한 내용은 "java -Xrunhprof:help" 명령어를 통해 확인할 수 있음
  3. 테스트 항목
    • StopWatch 를 사용한 메서드 시작과 종료 직전의 시각을 측정
    • runhprof 옵션을 통한 cpu 타임 샘플링

Heading 테스트 케이스 및 테스트 소스와 소요시간(단위 밀리세컨드)#

@Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 100000; i++) {
        LOGGER.info("a" + "b" + "c" + "d");
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 7839, 1170
  2. total time, cpu time : 8288, 1146
  3. total time, cpu time : 8123, 1129
  4. total time, cpu time : 8228, 1180
  5. total time, cpu time : 8093, 1222

@Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 100000; i++) {
        LOGGER.info("abcd");
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 7854, 1132
  2. total time, cpu time : 7920, 1169
  3. total time, cpu time : 8078, 1226
  4. total time, cpu time : 7931, 1153
  5. total time, cpu time : 8072, 1118
 @Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 100000; i++) {
        if (LOGGER.isInfoEnabled()) {

        }
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 3, 104
  2. total time, cpu time : 3, 107
  3. total time, cpu time : 4, 103
  4. total time, cpu time : 3, 107
  5. total time, cpu time : 2, 106
찍히지 않는 형태),10만번,slf4j
 @Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 100000; i++) {
        LOGGER.debug("abcd");
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 3, 106
  2. total time, cpu time : 4, 104
  3. total time, cpu time : 3, 105
  4. total time, cpu time : 3, 106
  5. total time, cpu time : 3, 104
 @Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 1000000; i++) {
        LOGGER.info("a" + "b" + "c" + "d");
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 74702, 11390
 @Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 1000000; i++) {
        LOGGER.info("{}{}{}{}", new Object[] {"a", "b", "c", "d"});
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 76899, 11532
 @Test
public void test() {
    StopWatch watch = new StopWatch();
    watch.start();
    for (int i = 0; i < 100000; i++) {
        LOGGER.debug(ReflectionToStringBuilder.toString(article, ToStringStyle.MULTI_LINE_STYLE));
    }
    watch.stop();
    LOGGER.info(String.valueOf(watch.getTotalTimeMillis()));
}
  1. total time, cpu time : 12985, 2656

Heading 평균수치(단위 밀리세컨드)#

  1. 문자열 연산(O), 10만번, slf4j
    • total time, cpu time : 8114.2, 1169.4
  2. 문자열 연산(X), 10만번, slf4j
    • total time, cpu time : 7971, 1159.6
  3. 로그레벨 체크, 10만번, slf4j
    • total time, cpu time : 3, 105.4
  4. 로그레벨보다 하위레벨로 로깅(실제로는 찍히지 않는 형태), 10만번, slf4j
    • total time, cpu time : 3.2, 105
  5. 문자열 연산(O), 100만번, log4j
    • total time, cpu time : 74702, 11390
  6. 문자열 연산(O), 100만번, slf4j
    • total time, cpu time : 76899, 11532
  7. ReflectionToStringBuilder 연산, 10만번, slf4j
    • total time, cpu time : 12985, 2656

Heading 정리#

  1. 1, 2번 경우를 볼때, 문자열 연산으로 인한 차이(8114, 7971)가 크지 않은 것 같다.
  2. Logger로 찍어주는 문자열 자체가 연산에 의해 생성될 경우 LOGGER.isInfoEnabled() 형태로 체크하는 것이 성능상 좋을 수 있다.
  3. Logger로 찍어주는 문자열 자체가 특별한 연산에 의해 생성되는 경우가 아닐 경우, Logger 자체가 로그 레벨 체크 후 로깅 여부를 판단하는데 LOGGER.isInfoEnabled() 형태로 체크하지 않아도 특별한 성능상의 차이가 발생하지 않을 것으로 보인다.
  4. 5, 6번 경우를 볼때, log4j와 slf4j의 성능차가 크다고 보기는 어렵다.
  5. ReflectionToStringBuilder.toString() 처럼 문자열을 생성하는 연산의 비용이 클 경우 LOGGER.isInfoEnabled() 를 사용해서 체크하는 것이 좋다.

Add new attachment

Only authorized users are allowed to upload new attachments.
« This page (revision-1) was last changed on 30-Dec-2010 10:58 by DongGukLee