태그 보관물: log

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

앱을 개발하고, 테스트를 하다 보면 종종 특정 로직의 실행시간이 궁금한 경우가 많다. 그래서 메서드의 실행시간을 로깅할 수 있는 것을 찾아보니 안드로이드 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

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

sjava-logging 1.0 Level

sjava-logging library는 level에 따른 로깅 가능여부를 체크하고 있지는 않습니다.
아래의 Level은 로깅파일의 분류 및 파일의 내용에 기입을 하기 위한 클래스입니다.
그리고, Level에 대한 사용을 위해서는 LevelFactory를 사용하면 됩니다.

LevelFactory.java

package net.sjava.logging;

import java.util.Map;
import java.util.HashMap;

/**
 *
 * @author mcsong@gmail.com
 * @since 2009. 7. 1.
 */
public class LevelFactory {   
    /** map of levels     */
    private Map<String, Level> levelMap;

    /** singleton instance */
    private static LevelFactory instance = new LevelFactory();
   
    /** constructor */
    private LevelFactory() {
        this.levelMap = new HashMap<String, Level>();
       
        this.levelMap.put(“all”, new Level(0, “all”));
        this.levelMap.put(“fatal”, new Level(1, “fatal”));
        this.levelMap.put(“error”, new Level(2, “error”));
        this.levelMap.put(“warn”, new Level(3, “warn”));
        this.levelMap.put(“info”, new Level(4, “info”));
        this.levelMap.put(“debug”, new Level(5, “debug”));
        this.levelMap.put(“trace”, new Level(6, “trace”));
        this.levelMap.put(“system”, new Level(7, “system”));
    }
   
    /**
     *
     * @return
     */
    public static LevelFactory getInstance() {
        return instance;
    }
   
    /**
     *
     * @param level
     * @return
     */
    public Level getLevel(int level) {
        switch (level) {
        case 1:
            return this.getLevel(“fatal”);
        case 2:
            return this.getLevel(“error”);
        case 3:
            return this.getLevel(“warn”);
        case 4:
            return this.getLevel(“info”);
        case 5:
            return this.getLevel(“debug”);
        case 6:
            return this.getLevel(“trace”);
        case 7:
            return this.getLevel(“system”);
           
        default:
            return this.getLevel(“all”);
        }
    }
   
    /**
     *
     * @param name
     * @return
     */
    public Level getLevel(String name) {
        if (name == null)
            return null;
       
        if(!this.levelMap.containsKey(name.toLowerCase()))
            return (Level)this.levelMap.get(“all”);
       
        return (Level)this.levelMap.get(name.toLowerCase());
    }
}

Level.java

package net.sjava.logging;

/**
 *
 * @author mcsong@gmail.com
 * @since 2009. 6. 19.
 */

public class Level {

    /** level number */
    public int level;
   
    /** level name */
    public String name;

    /**
     * Constructor
     *
     * @param level
     * @param name
     */
    public Level(int level, String name) {
        this.level = level;
        this.name = name;
    }
   
    /**
     * @return the level
     */
    public int getLevel() {
        return level;
    }

    /**
     * @param level the level to set
     */
    public void setLevel(int level) {
        this.level = level;
    }

    /**
     * @return the name
     */
    public String getName() {
        return name;
    }

    /**
     * @param name the name to set
     */
    public void setName(String name) {
        this.name = name;
    }

    @Override
    public String toString() {
        return “name is ” + this.name + “, level is ” + this.level;
    }
}