특정 로직에 대해서 성능 확인 (속도 체크) - stopwatch

자바(java)에서 특정 로직이 얼마나 소요되는지 체크를 하는 방법을 소개한다.

속도체크

View more presentations from knight1128.

1. jdk에서 제공하는 System 클래스의 currentTimeMillis() 메소드를 이용해서 확인할 수 있다.

예제

long startTime = System.currentTimeMillis();
Thread.sleep(1000);
long estimatedTime = System.currentTimeMillis() - startTime;
System.out.println("took " + estimatedTime + " ms");

결과값은 밀리세컨드(ms)로 다음과 같다.

took 1000 ms

2. jdk에서 제공하는 System 클래스의 nanoTime() 메소드를 이용해서 확인할 수 있다. 아주 정확한 시간을 측정할 때 많이 활용한다.

예제

long time1 = System.nanoTime();
Thread.sleep(1000);
long time2 = System.nanoTime();
long timeSpent = time2 - time1;
System.out.println("took " + timeSpent + " ns");

결과값은 nano 값으로 나온다.

took 1000232514 ns

3. Common-lang의 StopWatch 클래스를 이용한다. (commons-lang 2.3)

예제

import org.apache.commons.lang.time.StopWatch;

StopWatch stopWatch = new StopWatch();
stopWatch.reset();
stopWatch.start();
Thread.sleep(2000);
stopWatch.stop();
System.out.println(stopWatch.toString());
  
stopWatch.reset();
stopWatch.start();
Thread.sleep(5000);
stopWatch.stop();
System.out.println(stopWatch.toString());
  
stopWatch.reset();
stopWatch.start();
Thread.sleep(3000);
stopWatch.stop();
System.out.println(stopWatch.toString());

start를 하기전에 반드시 reset()를 해야 한다. 그 이유는 Common-lang의 StopWatch 클래스는 내부적으로 status를 가지고 있다. 이 부분에 대해서 약간 신경써야 한다. 자세한 것은 뒤에서 다시 설명한다.

결과값은 다음과 같다.

0:00:02.000
0:00:05.000
0:00:03.000

4. Spring core lib에 있는 util성 StopWatch 클래스를 이용한다. (Spring 3.0.x)

예제

import org.springframework.util.StopWatch;

...
StopWatch stopWatch = new StopWatch("Stop Watch");
stopWatch.start("initializing");
Thread.sleep(2000);
stopWatch.stop();
System.out.println("took " + stopWatch.getLastTaskTimeMillis() + " ms");

stopWatch.start("processing");
Thread.sleep(5000);
stopWatch.stop();
System.out.println("took " + stopWatch.getLastTaskTimeMillis() + " ms");
  
stopWatch.start("finalizing");
Thread.sleep(3000);
stopWatch.stop();
System.out.println("took " + stopWatch.getLastTaskTimeMillis() + " ms");
  
System.out.println(stopWatch.toString());
System.out.println();
System.out.println(stopWatch.prettyPrint());

결과 화면

took 2000 ms
took 5000 ms
took 3001 ms
StopWatch 'Stop Watch': running time (millis) = 10001; [initializing] took 2000 = 20%; [processing] took 5000 = 50%; [finalizing] took 3001 = 30%

StopWatch 'Stop Watch': running time (millis) = 10001
-----------------------------------------
ms     %     Task name
-----------------------------------------
02000  020%  initializing
05000  050%  processing
03001  030%  finalizing

얼마나 소요되었는지, 그동안의 관련정보를 계속 모아서, Task 별로 모아 정보를 출력한다.

5. 그냥 인터넷에서 남들이 만든 StopWatch를 찾아서 copy&paste한다.

http://www.devdaily.com/blog/post/java/stopwatch-class-that-can-be-used-for-timings-benchmarks



* Commons-lang의 StopWatch와 Spring Util의 StopWatch를 간단히 비교하였다.

	Commons-lang의 StopWatch 클래스	Spring util의 StopWatch 클래스
FQN	org.apache.commons.lang.time.StopWatch	org.springframework.util.StopWatch
메모리	경량화	Commons-lang의 Stopwatch보다는 메모리 조금 더 소요 (Task로 관리)
사용성	O	<OO (통계를 내주니까..)
기본 메소드	Start(), stop(), reset(), suspend(), resume()	Start(),stop()
이름(id)	X	O
Running status	Unstarted, running, stopped, suspended   상태가 있기 때문에 규칙이 있음   you cannot now call stop before start, resume before suspend or unsplit before split.   1. split(), suspend(), or stop() cannot be invoked twice 2. unsplit() may only be called if the watch has been split() 3. resume() may only be called if the watch has been suspend() 4. start() cannot be called twice without calling reset()	Running, not running
Split	기능 :시계에서처럼 split 기능   Status : Unsplit, split   Split(), Unsplit(), getSplitTime(), toSplitString()	X
Start시 task name	X	O
Print	O toString()	O toString() shortSummary() prettyPrint 누적시간을 기준으로 출력
Keeping track	X	O setKeepTaskList(boolean keepTaskList) 디폴트값은 true
isRunning	X	O isRunning()
Last time	X	O getLastTaskTimeMillis()
Total time	X	O getTotalTimeSeconds() getTotalTimeMillis()
Task count	X	O getTaskCount()

추가 - guava stopwatch 

예제

import java.util.concurrent.TimeUnit;

import org.junit.Test;

import com.google.common.base.Stopwatch;

public class GuavaTest {

@Test
public void test() {

Stopwatch stopwatch = Stopwatch.createStarted();

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

System.out.println("Elapsed time : " + stopwatch);
System.out.println("Elapsed time (milliseconds) : " + stopwatch.elapsed(TimeUnit.MILLISECONDS));
System.out.println("Elapsed time (microseconds) : " + stopwatch.elapsed(TimeUnit.MICROSECONDS));
System.out.println("Elapsed time (nanoseconds) : " + stopwatch.elapsed(TimeUnit.NANOSECONDS));
                

                                stopwatch.stop();

}

결과

Elapsed time : 1.001 s

Elapsed time (nanoseconds) : 1004995000

Elapsed time (microseconds) : 1005043

Elapsed time (Milliseconds) : 1005