Java/Tuning2009. 2. 23. 18:28

※이 문서는 Java Performance and Scalability Volume1(by Dov Bulka)라는 책의

2:Pure Overhead 읽고 나름대로 정리한 것입니다. ( 장은 기본적인 내용이 많아서 많은 부분이 생략되었답니다.)

 

Preface …

얻은 것이 있으면 잃는 것도 있는 법이다. 성능을 최적화 하면 종종 유연성, 유지보수성, 비용, 재사용성 같은 소프트웨어의 다른 중요한 목표들을 잃어버린다. 그러나 우리는 가끔 먼가를 공짜로 얻는 경우도 있다. 평소에 저지르는 간단한 코딩 실수를 고침으로서 아무런 희생도 없이 좋은 성능을 얻을 있다.

 

1. Useless Computations

소프트웨어에서는 우리가 전적으로 필요로 하는 것만을 계산하게끔 하는 것이 이상적이다. 이상에서 벗어나는 정도는 프로그램의 비효율성과 직결된다. 가능하면 불필요한 계산을 0 레벨로 줄이는 것이 좋다.

이를 위한 예제로 디버깅용으로 쓰이는 트레이스가 좋을것 같다. 세상에서 가장 간단한 트레이스 툴을 만들어보자.

 

public class Trace{

private static boolean loggingIsOn = false;

     private int myInt;

 

     public static void log(String msg) {

            if(loggingIsOn == true) System.out.println(msg);

     }

     public static void setLoggingIsOn(boolean newState) {

            loggingIsOn = newState;

     }

     public static boolean logging() {

            return loggingIsOn;

     }

}

Trace 클래스는 loggingIsOn 이라는 private static 멤버를 가지고 있다. 이것이 true이면 트레이싱을 하고 false이면 아무 작업도 하지 않는다. 전형적인 사용예는 다음과 같다.

public void doIntTrace(int i){

     Trace.log("Enter doIntTrace(). Input arg is " + i);

     myInt = i+1;

     Trace.log("Exit doIntTrace()");

}

 아주 간단한 메소드이다. 메소드에 들어오고 나갈때 추적정보를 남길뿐이다. 트레이스 기능이 켜져 있다면 우리는 별로 성능 문제에 신경을 쓰지 않을것이다(당연히 작동을 하는 것이니까,그리고 이는 주로 개발 도중에 사용하기 위한 것이다). 정작 문제가 되는건 개발이 끝나서 기능을 Off 했을때의 성능 문제이다. 쓰지도 않는 코드가 프로그램의 성능에 영향을 미쳐서는 절대로 안된다. 일단, 대부분은 프로그래머는 I/O 비싼 작업이라는 알고있다. Trace 클래스를 작성한 사람은

if(loggingIsOn == true) System.out.println(msg);

이라는 코드를 보고 트레이스 기능이 꺼져 있을때는 I/O 작업이 일어나지 않는다는 사실을 인식했다. 그러나 과연 이것으로 충분할까? 성능에 전혀 문제가 되지 않을까? 한번 측정을 해보자. 트레이싱을 하는 코드가 들어있는 doIntTrace()라른 메소드와 트레이싱을 하는 코드가 전혀 없는 doInt()라는 메소드를 비교해보자.

public void doInt(int i){

myInt = i+1;

}

 아래 예제와 같이 루프를 돌려서 실행 시간을 측정하였다.

(예제1) 실행시간 : 250 ms

for(int i=0; i<1000000; i++){

            tr.doInt(i);

     }

 

(예제2) 실행시간 : 10,400 ms

for(int i=0; i<1000000; i++){

            tr.doIntTrace(i);

     }

트레이싱을 하는 코드가 없을때가 무려 40배나 빠르다. 이유를 자세히 분석하기 위해 doIntTrace() 실행한 것을 프로파일링 해보았다.

 java –Xrunhprof:cpu=times TraceTester 10000

   (TraceTester doIntTrace() 들어있는 클래스 이름, 10000 반복횟수)

 프로파일링 결과는 아래 표와 같다.

 

rank  self    accum    count  trace    method

   1   11.35% 11.35%   10000    10 Trace.doIntTrace

   2   7.03%  18.38%    10000     8 java.lang.StringBuffer.append

   3   6.49%  24.86%    10000    18 java.lang.String.valueOf

   4   5.95%  30.81%    10003    11 java.lang.String.<init>

   5   5.41%  36.22%    10000    15 java.lang.StringBuffer.append

   6   4.86%  41.08%    10000    27 java.lang.StringBuffer.append

   7   4.32%  45.41%    10000     2 java.lang.String.getChars

   8   3.78%  49.19%    10000     6 java.lang.StringBuffer.<init>

   9   3.78%  52.97%    10003    12 java.lang.System.arraycopy

  10   3.78%  56.76%    10000    19 java.lang.String.<init>

  11   3.78%  60.54%    10000    17 java.lang.StringBuffer.toString

  12   3.78%  64.32%     9990    20 java.lang.StringBuffer.expandCapacity

  13   3.24%  67.57%    10000    14 java.lang.System.arraycopy

  14   3.24%  70.81%        1    29 Trace.main

  15   3.24%  74.05%    10000    23 java.lang.StringBuffer.expandCapacity

  16   3.24%  77.30%    10000     9 java.lang.Integer.toString

  17   2.70%  80.00%    10000    33 java.lang.String.getChars

  18   2.70%  82.70%    10003    24 java.lang.Integer.toString

  19   2.70%  85.41%    10000    25 java.lang.StringBuffer.setShared

  20   2.16%  87.57%    10003    16 java.lang.System.arraycopy

  21   2.16%  89.73%    10000     5 java.lang.System.arraycopy

  22   1.62%  91.35%    10000    13 java.lang.StringBuffer.<init>

  23   1.62%  92.97%    20000    26 Trace.log

  24   1.62%  94.59%     9990    31 java.lang.System.arraycopy

 (: 위의 표는 너구리가 직접 작성한 것임. PC에서 대로 해보았더니 underflow 에러가 나서 for문은 10000 번만 돌리고 프로파일링 횟수는 1번만 했음. 결과 성향은 비슷~.

직접 해보시길 권장합니다. 이런 잼있는 기능이 있는줄 몰랐습니다. ^^)

 

 결과를 찬찬히 살펴보면 대부분의 작업이 String StringBuffer 관련된 작업이라는 것을 있다. 다시말해서 log() 메소드에서 파라미터 String 생성하는 오버헤드가 프로그램을 잡아먹은 것이다.

  Trace.log("Enter doIntTrace(). Input arg is " + i);

 표에서 보면 우리가 호출한 두번의 Trace.log() 의한 오버헤드는 2% 안된다. 머가 문제였을까? 가장 문제는 쓰지도 않고 바로 버려질 String 객체가 매번 파라미터로 생성되었다는 점이다. 코드에서는 트레이스가 켜져 있건 꺼져 있던간에 상관없이 String 객체가 생성되어 넘어가 버린다. log()메소드에서 트레이스 상태를 체크할때는 이미 늦는다. 앞장에서 계속 언급했듯이 이는 새로운 객체의 생성, 그리고 가비지 컬렉션이라는 두가지의 비싼 비용을 불필요하게 계속 지불한 셈이다. 코드에서 객체를 많이 생성할수록 가비지 컬렉터는 청소를 하기 위해 힘든 일을 해야한다.

 위의 예제는 상상에 의한 허구가 아니다. 실제로 이렇게 하는 경우를 많이 보았다. 물론 실제의 경우는 심각하다. 전형적인 트레이스 메시지는 아래와 같은 경우가 많았다.

  Trace.log(“Enter method X with two integer arguments: “ +

              “ a = “ + a + “ b = “ + b);

  코드에서 인자로 넘어갈 문자열을 만드는 작업을 살펴보자. : 두번의 integer-String 변환, 하나의 StringBuffer 생성, 일련의 StringBuffer.append() 메소드 호출. 많은 작업들은 전혀 필요하지 않다. 트레이싱 기능은 꺼져 있으므로 쓰레기가 뿐이다.

 

 해결책은 간단하다. 트레이스 클래스에 현재 상태를 있는 메소드가 있으므로 트레이싱이 켜져있지 않으면 문자열 인자를 생성하지 않는 것이다.

 public void doIntTrace(int i){

if(Trace.logging()) Trace.log("Enter doIntTrace(). Input arg is " + i);

myInt = i+1;

if(Trace.logging()) Trace.log("Exit doIntTrace()");

}

이전에 행한것과 같이 루프를 돌려보면 350 ms 밖에 걸리지 않는다. 일단 많이 향상은 되었다. 그러나 아직은 Trace.logging() 의한 오버헤드가 남아있다. 다음절에서 계속하자.

 

2. Making Overhead Vanish

  트레이스 기능이 꺼져 있을때 아직 if 문에 의한 오버헤드가 남았다.

    if(Trace.loggingIsOn) {...}

 logginIsOn 이라는 멤버 변수를 상수로 선언해버림으로써 우리는 문제를 아주 간단히 해결할 있다.

  class Trace{

     public static final boolean logginIsOn = false;

     ...

  }

상수가 되었으므로 트레이스가 꺼져 있는 상태라면

 if(Trace.loggingIsOn) {...}

 if(false) {...}

같다. 상수이기 때문에 위와 같이 인식이 것이고 위와 같은 코드는 죽은 코드가 되어서 좋은 컴파일러는 이를 인식하고 이러한 코드를 없에버린다.

 

출처 : 너구리님 워드파일

Posted by Huikyun