[Concurrency] - ThreadPoolExecutor 를 이용한 Thread 동작 시간 구하기

ThreadPoolExecutor 는  beforeExecute, afterExecute, terminated 등의 훅 메소드를 제공한다.
ThreadPoolExecutor 클래스를 상속받은 TimingThreadPoolExecutor 를 사용하여 쓰레드의 동작 시간을 알 수 있다.

성능 테스트 시 유용하게 사용할 수 있을듯..(아니면 말구..)

TimingThreadPoolExecutor.java

package study.threadpool.timing;

import java.util.concurrent.BlockingQueue;
import java.util.concurrent.RejectedExecutionHandler;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
import java.util.logging.Logger;

public class TimingThreadPoolExecutor extends ThreadPoolExecutor {

    public TimingThreadPoolExecutor(int corePoolSize,
            int maximumPoolSize,
            long keepAliveTime,
            TimeUnit unit,
            BlockingQueue<Runnable> workQueue) {
  super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
 }

 private final ThreadLocal<Long> startTime = new ThreadLocal<Long>();
    private final AtomicLong numTasks = new AtomicLong();
    private final AtomicLong totalTime = new AtomicLong();

    protected void beforeExecute(Thread t, Runnable r) {
        super.beforeExecute(t, r);
        startTime.set(System.nanoTime());
    }

    protected synchronized void afterExecute(Runnable r, Throwable t) {
        try {
            long endTime = System.nanoTime();
            long taskTime = endTime - startTime.get();
            numTasks.incrementAndGet();
            totalTime.addAndGet(taskTime);
        } finally {
            super.afterExecute(r, t);
        }
    }

    protected synchronized void terminated() {
        try {
         System.out.println("Terminated:");
         System.out.println(String.format(" total    time=%dns", totalTime.get()));
         System.out.println(String.format(" numTasks time=%d", numTasks.get()));        
            System.out.println(String.format(" avg time=%dns", (totalTime.get() / numTasks.get())));
                    
        } finally {
            super.terminated();
        }
    }
}

Work.java
- 하는일 없이 3초동안 잠만 자는 놈.

package study.threadpool.timing;

public class Work implements Runnable {

 @Override
 public void run() {
  // TODO Auto-generated method stub
  try {
   for(int i = 0;i<3;i++) {
    System.out.println("running...[" + i + "]");
    Thread.sleep(1000);
   }
  } catch (InterruptedException e) {
   // TODO Auto-generated catch block
   e.printStackTrace();
  }
 }
}

Launcher.java

import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.BlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

public class Launcher {

 final ThreadPoolExecutor pool;
 final BlockingQueue<Runnable> queue;

 public Launcher() {
  queue    = new ArrayBlockingQueue<Runnable>(1);
  pool    = new TimingThreadPoolExecutor(1, 1, 30, TimeUnit.SECONDS, queue);
 }
 
 public void test() {
  for(int i = 0;i<2;i++)
   pool.execute(new Work());
 
  pool.shutdown();
 }
 public static void main(String[] args) {
  new Launcher().test();
 }
}

결과
- 1.5 이상부터 System.nanoTime() 지원 됨.

running...[0]
running...[1]
running...[2]
running...[0]
running...[1]
running...[2]
Terminated:
 total    time=5999990250ns
 numTasks time=2
 avg time=2999995125ns