날짜: 2016 7월 28

실행시간을 로깅할 수 있는 TimingLogger 클래스 개선

Posted on by mcsong with Leave a comment

앱을 개발하고, 테스트를 하다 보면 종종 특정 로직의 실행시간이 궁금한 경우가 많다. 그래서 메서드의 실행시간을 로깅할 수 있는 것을 찾아보니 안드로이드 API에서 TimingLogger라는 클래스를 제공하고 있다.
API 문서를 살펴보니, 사용방법은 다음과 같다. 

TimingLogger timings = new TimingLogger(TAG, "methodA");
// ... do some work A ...
timings.addSplit("work A");
// ... do some work B ...
timings.addSplit("work B");
// ... do some work C ...
timings.addSplit("work C");
timings.dumpToLog();

그리고, 이 코드의 실행결과는 아래에서 보듯이 실행시간과 로깅 데이터를 보여준다. 

D/TAG     ( 3459): methodA: begin
D/TAG     ( 3459): methodA:      9 ms, work A
D/TAG     ( 3459): methodA:      1 ms, work B
D/TAG     ( 3459): methodA:      6 ms, work C
D/TAG     ( 3459): methodA: end, 16 ms

API 문서만 봐서는 간단하게 메서드의 실행시간을 확인하는데 꽤 유용하게 사용할 수 있어 보인다. 그러나 TimingLogger 클래스를 자세히 보니, 로그 레벨이 Log.VERBOSE로 하드코딩되어 있어서 실제로는 사용하기 불편하다. 그래서, 간단하게 TimingLogger에 로깅레벨을 설정해서 사용할 수 있도록 TimingLogger 클래스를 개선해 봤다.

TimingLogger 클래스 소스 : https://github.com/android/platform_frameworks_base/blob/master/core/java/android/util/TimingLogger.java

이 클래스에 로깅레벨을 추가하고 추가한 로깅레벨을 기준으로 수정한 dumpToLog() 메서드는 다음과 같다. 

/** LogLeve to check log or not */
private static int mLogLevel = Log.DEBUG;

public static void setLogLevel(int logLevel) {
    mLogLevel = logLevel;
}

public void dumpToLog() {
    if (mDisabled) return;

    final long first = mSplits.get(0);
    long now = first;
    for (int i = 1; i < mSplits.size(); i++) {
        now = mSplits.get(i);
        final String splitLabel = mSplitLabels.get(i);
        final long prev = mSplits.get(i - 1);

        Log.println(mLogLevel, mTag, mLabel + ":      " + (now - prev) + " ms, " + splitLabel);
    }
    Log.println(mLogLevel, mTag, mLabel + ": end, " + (now - first) + " ms");
}

이 TimingLogger 클래스를 수정한 클래스인 JTimingLogger 클래스는 개인 프로젝트인 AndoridUtil 라이브러리 프로젝트에서 볼 수 있다.

JTimingLogger 클래스 소스 : https://github.com/mcsong/AndoridUtil/blob/master/library/src/main/java/net/sjava/androidutil/JTimingLogger.java

다음으로 이 클래스를 사용하는 예제를 살펴보자. 

import net.sjava.androidutil.JTimingLogger;

public class MainActivity extends AppCompatActivity {

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);
        display();
    }
    
    public void display() {
        Log.d("AA", "1111111111111111");

        JTimingLogger.setLogLevel(Log.INFO);
        JTimingLogger.setLogLevel(Log.VERBOSE);

        JTimingLogger logger = new JTimingLogger("AA", "VV");
        logger.addSplit("aaaaaaaaaaaaaaa");

        try {
            Thread.sleep(100);

            logger.addSplit("aaaaaaaaaaaaaaa");

            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        logger.addSplit("bbb");
        logger.dumpToLog();
    }
}

이 소스를 사용하는 방법으로, 사용하기 전에 JTimingLogger.setLogLevel() 메서드에 로그레벨을 설정하고 사용하면 된다. 그리고 이 소스를 실행한 화면은 다음과 같다. 

07-27 20:47:39.713 12502-12502/net.sjava.androidutil.demo I/AA: VV:      0 ms, aaaaaaaaaaaaaaa
07-27 20:47:39.714 12502-12502/net.sjava.androidutil.demo I/AA: VV:      100 ms, aaaaaaaaaaaaaaa
07-27 20:47:39.715 12502-12502/net.sjava.androidutil.demo I/AA: VV:      101 ms, bbb
07-27 20:47:39.715 12502-12502/net.sjava.androidutil.demo I/AA: VV: end, 201 ms

이제 간단하게 확인하고 싶은 메서드의 실행시간을 쉽게 확인할 수 있다.

Posted in Android