Java ログにスレッド、メソッドの実行時間を出力する

今回作成したプロジェクトはGitHubにアップしています。
https://github.com/kaishero/mylogger

1.ログクラス

```lang:MyLogger
package javasample.mylogger;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MyLogger {

    private Logger logger;
    private static ThreadLocal<Long> time = new ThreadLocal<Long>() {
        @Override
        protected Long initialValue() {
            return null;
        }
    };

    private MyLogger() {
    }

    public MyLogger(final Class clazz) {
        this.logger = LoggerFactory.getLogger(clazz);
    }

    /**
     * スレッド開始.
     * infoレベル
     */
    public void thredStart() {
        String methodName = Thread.currentThread().getStackTrace()[2].getMethodName();
        time.set(System.nanoTime());
        logger.info(
                "{} Thred START! execTime = {} [ms]",
                methodName,
                getTime());
    }

    /**
     * スレッド終了.
     * infoレベル
     */
    public void thredEnd() {
        String methodName = Thread.currentThread().getStackTrace()[2].getMethodName();
        logger.info(
                "{} Thred END! execTime = {} [ms]",
                methodName,
                getTime());
        // スレッドローカル破棄
        time.remove();
    }

    /**
     * メソッド開始.
     * debugレベル
     */
    public void start() {
        String methodName = Thread.currentThread().getStackTrace()[2].getMethodName();
        logger.debug(
                "{} START! execTime = {} [ms]",
                methodName,
                getTime());
    }

    /**
     * メソッド終了.
     * debugレベル
     */
    public void end() {
        String methodName = Thread.currentThread().getStackTrace()[2].getMethodName();
        logger.debug(
                "{} END! execTime = {} [ms]",
                methodName,
                getTime());
    }

    public void info(final String message) {
        logger.info(message);
    }

    public void info(final String format, Object o) {
        logger.info(format, o);
    }

    public void info(final String format, Object... os) {
        logger.info(format, os);
    }

    public void debug(final String message) {
        logger.debug(message);
    }

    public void debug(final String format, Object o) {
        logger.debug(format, o);
    }

    public void debug(final String format, Object... os) {
        logger.debug(format, os);
    }

    public void warn(final String message) {
        logger.warn(message);
    }

    public void warn(final String format, Object o) {
        logger.warn(format, o);
    }

    public void warn(final String format, Object... os) {
        logger.warn(format, os);
    }

    public void error(final String message) {
        logger.error(message);
    }

    public void error(final String format, Object o) {
        logger.error(format, o);
    }

    public void error(final String format, Object... os) {
        logger.error(format, os);
    }

    private double getTime() {
        return (double) (System.nanoTime() - time.get()) / 1000000d;
    }
}
```

2.ログを出力してみる

スレッド開始メソッドの最初にthredStart()、最後にthredEnd()
各メソッドの最初にstart()、最後にend()

```lang:App.java
package javasample.mylogger;

public class App {

    private static MyLogger logger = new MyLogger(App.class);

    public static void main(String[] args) throws InterruptedException {
        logger.thredStart();

        Thread.sleep(50);
        
        appMethod("abc");

        NewClass obj = new NewClass();
        obj.newMethod();

        logger.thredEnd();
    }

    private static void appMethod(String str) throws InterruptedException {
        logger.start();
        logger.debug("param str = {}", str);
        Thread.sleep(80);
        logger.end();
    }
}
```

下記のように出力される
スレッドの実行時間が約234[ms]なのがわかる

```
22:43:58.367 [main] INFO  javasample.mylogger.App - main Thred START! execTime = 0.01561 [ms]
22:43:58.419 [main] DEBUG javasample.mylogger.App - appMethod START! execTime = 55.098761 [ms]
22:43:58.419 [main] DEBUG javasample.mylogger.App - param str = abc
22:43:58.499 [main] DEBUG javasample.mylogger.App - appMethod END! execTime = 135.245087 [ms]
22:43:58.500 [main] DEBUG javasample.mylogger.NewClass - newMethod START! execTime = 136.323083 [ms]
22:43:58.599 [main] DEBUG javasample.mylogger.NewClass - return i = 99
22:43:58.599 [main] DEBUG javasample.mylogger.NewClass - newMethod END! execTime = 234.736799 [ms]
22:43:58.599 [main] INFO  javasample.mylogger.App - main Thred END! execTime = 234.882093 [ms]
```