How to gracefully count code time

Click on the official account ,Java dried food Timely delivery

One 、 Preface

Code time consumption statistics is a very common requirement in daily development , Especially when you need to find the performance bottleneck of your code .

It may also be limited by Java Language characteristics of , I always feel that the code is not elegant enough , A lot of time-consuming statistical code , It interferes with the business logic . Especially when developing functions , There is a feeling that the code is fresh and elegant just after development , As a result, after adding a lot of auxiliary code , The whole code becomes bloated , It's hard to look at myself . So I always want to write this piece more elegantly , Today, this article tries to discuss “ Code time consumption statistics ” This piece of .

Before starting the text , Let's start with the premise ,“ Code time consumption statistics ” It's not the time-consuming of a method that matters , It's time-consuming between arbitrary code segments . This code snippet , It could be a few lines of code in a method , It can also be from one line of this method to another line of the called method , So by AOP The way can't realize this demand .

Two 、 Conventional methods

2.1 Time difference statistics

This is the easiest way , Record the start time , Record the end time , Just calculate the time difference .

public class TimeDiffTest {
    public static void main(String[] args) throws InterruptedException {
        final long startMs = TimeUtils.nowMs();

        TimeUnit.SECONDS.sleep(5); //  Simulate business code 

        System.out.println("timeCost: " + TimeUtils.diffMs(startMs));
    }
}

/* output: 
timeCost: 5005

public class TimeUtils {
    /**
     * @return  The current number of milliseconds 
     */
    public static long nowMs() {
        return System.currentTimeMillis();
    }

    /**
     *  The current millisecond is less than the starting millisecond 
     * @param startMillis  Start nanoseconds 
     * @return  Time difference 
     */
    public static long diffMs(long startMillis) {
       return diffMs(startMillis, nowMs());
    }
}

The advantage of this method is that it is easy to realize , It's good for understanding ; The disadvantage is that the code is more intrusive , It looks stupid , Not elegant .

 It's awesome ！ Necessary for private work  N  Open source projects ！ Collect it quickly 

2.2 StopWatch

The second way is reference StopWatch ,StopWatch Usually used as a statistical code , Each frame and Common Packages have their own implementations .

public class TraceWatchTest {
    public static void main(String[] args) throws InterruptedException {
        TraceWatch traceWatch = new TraceWatch();

        traceWatch.start("function1");
        TimeUnit.SECONDS.sleep(1); //  Simulate business code 
        traceWatch.stop();

        traceWatch.start("function2");
        TimeUnit.SECONDS.sleep(1); //  Simulate business code 
        traceWatch.stop();

        traceWatch.record("function1", 1); //  Direct recording takes time 

        System.out.println(JSON.toJSONString(traceWatch.getTaskMap()));
    }
}

/* output: 
{"function2":[{"data":1000,"taskName":"function2"}],"function1":[{"data":1000,"taskName":"function1"},{"data":1,"taskName":"function1"}]}

public class TraceWatch {
    /** Start time of the current task. */
    private long startMs;

    /** Name of the current task. */
    @Nullable
    private String currentTaskName;

    @Getter
    private final Map<String, List<TaskInfo>> taskMap = new HashMap<>();

    /**
     *  Start time difference type indicator record , If it is necessary to terminate , Please call  {@link #stop()}
     *
     * @param taskName  Index name 
     */
    public void start(String taskName) throws IllegalStateException {
        if (this.currentTaskName != null) {
            throw new IllegalStateException("Can't start TraceWatch: it's already running");
        }
        this.currentTaskName = taskName;
        this.startMs = TimeUtils.nowMs();
    }

    /**
     *  End time difference type indicator record , Make sure that... Is called before calling 
     */
    public void stop() throws IllegalStateException {
        if (this.currentTaskName == null) {
            throw new IllegalStateException("Can't stop TraceWatch: it's not running");
        }
        long lastTime = TimeUtils.nowMs() - this.startMs;

        TaskInfo info = new TaskInfo(this.currentTaskName, lastTime);

        this.taskMap.computeIfAbsent(this.currentTaskName, e -> new LinkedList<>()).add(info);

        this.currentTaskName = null;
    }

    /**
     *  Record indicator data directly , Not limited to time difference types 
     *  @param taskName  Index name 
     * @param data  Indicator data 
     */
    public void record(String taskName, Object data) {
        TaskInfo info = new TaskInfo(taskName, data);

        this.taskMap.computeIfAbsent(taskName, e -> new LinkedList<>()).add(info);
    }

    @Getter
    @AllArgsConstructor
    public static final class TaskInfo {
        private final String taskName;

        private final Object data;
    }
}

I'm copying org.springframework.util.StopWatch The implementation of the , Yes TraceWatch class , This method provides two time-consuming statistical methods ：

• By calling Start(name) and Stop() Method , Time consuming Statistics .

• By calling Record(name, timeCost), Method , Direct recording of time-consuming information .

This approach is essentially the same as “ Time difference statistics ” It's consistent , It's just a layer , A little more elegant . in addition , Search official account python AI technology background reply “ classics ”, Get a surprise pack .

notes ： You can do it according to your business needs , Modify yourself TraceWatch Internal data structure , I'm here for simplicity , The internal data structure is just a random example .

3、 ... and 、 Advanced methods

The two methods mentioned in the second section , In the vernacular, it's all “ Go straight up and down ” The feeling of , We can also try to make the code a little easier .

3.1 Function

stay jdk 1.8 in , Introduced java.util.function package , Through the interface provided by this class , It can implement the function of executing extra code in the context of the specified code segment .

public class TraceHolderTest {
    public static void main(String[] args) {
        TraceWatch traceWatch = new TraceWatch();

        TraceHolder.run(traceWatch, "function1", i -> {
            try {
                TimeUnit.SECONDS.sleep(1); //  Simulate business code 
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        });

        String result = TraceHolder.run(traceWatch, "function2", () -> {
            try {
                TimeUnit.SECONDS.sleep(1); //  Simulate business code 
                return "YES";
            } catch (InterruptedException e) {
                e.printStackTrace();
                return "NO";
            }
        });

        TraceHolder.run(traceWatch, "function1", i -> {
            try {
                TimeUnit.SECONDS.sleep(1); //  Simulate business code 
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        });

        System.out.println(JSON.toJSONString(traceWatch.getTaskMap()));
    }
}

/* output: 
{"function2":[{"data":1004,"taskName":"function2"}],"function1":[{"data":1001,"taskName":"function1"},{"data":1002,"taskName":"function1"}]}

public class TraceHolder {
    /**
     *  Call with return value 
     */
    public static <T> T run(TraceWatch traceWatch, String taskName, Supplier<T> supplier) {
        try {
            traceWatch.start(taskName);

            return supplier.get();
        } finally {
            traceWatch.stop();
        }
    }

    /**
     *  No return value call 
     */
    public static void run(TraceWatch traceWatch, String taskName, IntConsumer function) {
        try {
            traceWatch.start(taskName);

            function.accept(0);
        } finally {
            traceWatch.stop();
        }
    }
}

Here I take advantage of Supplier and IntConsumer Interface , It provides call with return value and no return value , stay TraceHolder Class , Before and after the core code block , Respectively called the previous TraceWatch Methods , The function of time-consuming statistics is realized .

3.2 AutoCloseable

Besides using Function Characteristics of , We can also use jdk 1.7 Of AutoCloseable characteristic . say AutoCloseable Maybe some students haven't heard of it , But let's show you the following code , You'll immediately know what it is .

//  not used  AutoCloseable
public static String readFirstLingFromFile(String path) throws IOException {
    BufferedReader br = null;
    try {
        br = new BufferedReader(new FileReader(path));
        return br.readLine();
    } catch (IOException e) {
        e.printStackTrace();
    } finally {
        if (br != null) {
            br.close();
        }
    }
    return null;
}

//  Use  AutoCloseable
public static String readFirstLineFromFile(String path) throws IOException {
    try (BufferedReader br = new BufferedReader(new FileReader(path))) {
        return br.readLine();
    }
}

stay try Then you can load an implementation AutoCloseable Object of the interface , This object acts on the whole try In the block , And call back after execution AutoCloseable#close() Method . 

Let's be right TraceWatch Class transformation ：

• Realization AutoCloseable Interface , Realization close() Interface ：

@Override
public void close() {
    this.stop();
}

• modify start() Method , Make it support chain call ：

public TraceWatch start(String taskName) throws IllegalStateException {
    if (this.currentTaskName != null) {
        throw new IllegalStateException("Can't start TraceWatch: it's already running");
    }
    this.currentTaskName = taskName;
    this.startMs = TimeUtils.nowMs();
    
    return this;
}
public class AutoCloseableTest {
    public static void main(String[] args) {
        TraceWatch traceWatch = new TraceWatch();

        try(TraceWatch ignored = traceWatch.start("function1")) {
            try {
                TimeUnit.SECONDS.sleep(1); //  Simulate business code 
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }

        try(TraceWatch ignored = traceWatch.start("function2")) {
            try {
                TimeUnit.SECONDS.sleep(1); //  Simulate business code 
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }

        try(TraceWatch ignored = traceWatch.start("function1")) {
            try {
                TimeUnit.SECONDS.sleep(1); //  Simulate business code 
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }

        System.out.println(JSON.toJSONString(traceWatch.getTaskMap()));
    }
}

/* output: 
{"function2":[{"data":1001,"taskName":"function2"}],"function1":[{"data":1002,"taskName":"function1"},{"data":1002,"taskName":"function1"}]}
*/

Four 、 summary

This article lists four ways to count code time ：

• Time difference statistics

• StopWatch

• Function

• AutoCloseable

The solutions listed are the ones I can think of at present . Of course, there may be a more elegant solution , I hope that students with relevant experience can communicate with each other in the comment area ~

Do you have anything else to add ？

PS： Welcome to leave your opinion in the message area , Discuss improvement together . If today's article gives you new inspiration , Welcome to forward and share to more people .
 Today's good article recommendation 

GitHub It's very practical 40 Open source JAVA project 
XShell It's too expensive ？ Try open source NuShell, To use ！

GET  and  POST What is the essential difference between requests ？ After reading it, I feel too ignorant ...
MyBatis Bulk insert data you're still using foreach？ Your server didn't crash ？

 I'm looking at one less  bug