Thread 的產生時機與 Thread Pool 測試
首先，ExecutorService 創建時，可以指定 Thread Pool 的容量以及對應的 ThreadFactory
在 ThreadFactory 中可以定義如何產生 Thread，因此可以利用 ThreadFactory 來檢驗 Thread Pool 中的 Thread 的產生時機。
程式碼中分成兩個 .java 檔，一個是初始化 ExecutorService 並提供介面做排程的類別（Schedule.java），一個則是程式進入點（Test.java），進行排程設定的動作。
Schedule.java
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import org.apache.log4j.Logger;
public class Schedule {
private static ScheduledExecutorService SCHEDULER = null;
private static ThreadGroup handlingGroup = new ThreadGroup("ThreadGroup");;
private static Logger log = Logger.getLogger("Scheduler");
public static void initial () {
// Initiate a ExecutorService with pre-defined thread pool.
SCHEDULER = Executors.newScheduledThreadPool(2, new ScheduleHandlerThreadFactory("Threads"));
}
public static void schedule (Runnable command, long delay, TimeUnit timeUnit) {
SCHEDULER.schedule(command, delay, timeUnit);
}
private static class ScheduleHandlerThreadFactory implements ThreadFactory {
private int count = 1;
private String prefixString = null;
public ScheduleHandlerThreadFactory (String prefix) {
this.prefixString = prefix;
}
@Override
public Thread newThread(Runnable r) {
log.debug("Create thread #" + this.count);
return new Thread(handlingGroup, r, this.prefixString + "-" + this.count++);
}
}
}
在 Schedule.java 中，產生的 ExecutorService 是有兩個 Thread 的 Thread Pool，同時在產生 Thread 時會在 log 上印出現在產生的序號。
Test.java
import java.util.concurrent.TimeUnit;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
public class Test {
private static Logger LOG = LogManager.getLogger("Main");
public static void main(String[] args) {
LOG.debug("Initial scheduler.");
Schedule.initial();
LOG.debug("Sleep.");
try {
Thread.sleep(2000);
} catch (InterruptedException e) {}
LOG.debug("Set schedule #1.");
Schedule.schedule(new TestRunnable(), 0, TimeUnit.MILLISECONDS);
LOG.debug("Set schedule #2.");
Schedule.schedule(new TestRunnable(), 1000, TimeUnit.MILLISECONDS);
LOG.debug("Set schedule #3.");
Schedule.schedule(new TestRunnable(), 1000, TimeUnit.MILLISECONDS);
LOG.debug("Set schedule #4.");
Schedule.schedule(new TestRunnable(), 1000, TimeUnit.MILLISECONDS);
LOG.debug("Sleep again.");
try {
Thread.sleep(5000);
} catch (InterruptedException e) {}
LOG.debug("End");
System.exit(0);
}
public static class TestRunnable implements Runnable {
@Override
public void run() {
LogManager.getLogger(Thread.currentThread().getName()).debug("RUNNING by thread " + Thread.currentThread().getId());
}
}
}
在 Test.java 中，依序設定 4 個排程，其中第 2~4 個排程都是延後 1 秒才執行，以此來判斷 Thread 產生的時機。
最後印出的結果如下：
2014-02-19 12:03:14.637 | DEBUG | Main > Initial scheduler. 2014-02-19 12:03:14.644 | DEBUG | Main > Sleep. 2014-02-19 12:03:16.644 | DEBUG | Main > Set schedule #1. 2014-02-19 12:03:16.647 | DEBUG | Scheduler > Create thread #1 2014-02-19 12:03:16.649 | DEBUG | Main > Set schedule #2. 2014-02-19 12:03:16.649 | DEBUG | Scheduler > Create thread #2 2014-02-19 12:03:16.649 | DEBUG | Threads-1 > RUNNING by thread 12 2014-02-19 12:03:16.649 | DEBUG | Main > Set schedule #3. 2014-02-19 12:03:16.651 | DEBUG | Main > Set schedule #4. 2014-02-19 12:03:16.651 | DEBUG | Main > Sleep again. 2014-02-19 12:03:17.650 | DEBUG | Threads-2 > RUNNING by thread 13 2014-02-19 12:03:17.652 | DEBUG | Threads-1 > RUNNING by thread 12 2014-02-19 12:03:17.652 | DEBUG | Threads-2 > RUNNING by thread 13 2014-02-19 12:03:21.652 | DEBUG | Main > End
從印出的結果來看，可以看出 Thread Pool 中的第一個 Thread 是在第 4 行中第一個排程設定時被產生出來的，不是第 2 行就產生出來
所以 ExecutorService 的 Thread 並不會在宣告時就立即產生對應數量的 Thread Pool，而是在開始需要這個 Thread 的時候才產生。
而第二個 Thread 產生的時機也不是跟著第一個 Thread 之後馬上產生出來，而是第二個排程設定進去時才產生
除了驗證了上面的說法之外，同時也表示 Thread 的產生時機是在排程設定的時候，而不是排程真正開始執行的時候。
接著在每個排程執行時，Thread 的編號都是 12、13，也表示 ExecutorService 的確有讓大家共用同一個 Thread Pool～。
定時排程的時機測試
為了想了解 ExecutorService 在做定時排程時，Thread Pool 跟排程時間之間的關係，接著用以下的程式碼做了第二步測試。
程式碼中主要是把 Thread Pool 改成只有一個 Thread 的 Thread Pool
另外產生兩個一樣的任務，一個是主程式一開始就馬上執行、另一個會延遲兩秒才開始執行，任務的定時設定為每一分鐘執行一次
任務的 Runnable 改為印出開始執行的訊息後（訊息中夾帶當前時間）就暫停 10 秒。
程式碼如下：
Test.java
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Calendar;
import java.util.concurrent.TimeUnit;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
public class Test {
private static Logger LOG = LogManager.getLogger("Main");
public static void main(String[] args) {
LOG.debug("Initial scheduler.");
Schedule.initial();
LOG.debug("Sleep.");
try {
Thread.sleep(2000);
} catch (InterruptedException e) {}
LOG.debug("Set schedule #1.");
Schedule.scheduleWithFixedDelay(new TestRunnable(1), 0, 60000, TimeUnit.MILLISECONDS);
LOG.debug("Set schedule #2.");
Schedule.scheduleWithFixedDelay(new TestRunnable(2), 2000, 60000, TimeUnit.MILLISECONDS);
try {
Thread.sleep(50000000);
} catch (InterruptedException e) {}
LOG.debug("End");
System.exit(0);
}
public static class TestRunnable implements Runnable {
private int _number = 0;
DateFormat _formatter = new SimpleDateFormat ("hh:mm:ss");
public TestRunnable (int count) {
this._number = count;
}
@Override
public void run() {
LogManager.getLogger(Thread.currentThread().getName()).debug(
"Job #" + _number + " is running at " + _formatter.format(Calendar.getInstance().getTime()));
try {
Thread.sleep(10000);
} catch (InterruptedException e) {}
}
}
}
Schedule.java
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import org.apache.log4j.Logger;
public class Schedule {
private static ScheduledExecutorService SCHEDULER = null;
private static ThreadGroup handlingGroup = new ThreadGroup("ThreadGroup");;
private static Logger log = Logger.getLogger("Scheduler");
public static void initial () {
// Initiate a ExecutorService with pre-defined thread pool.
SCHEDULER = Executors.newScheduledThreadPool(1, new ScheduleHandlerThreadFactory("Threads"));
}
public static void schedule (Runnable command, long delay, TimeUnit timeUnit) {
SCHEDULER.schedule(command, delay, timeUnit);
}
public static void scheduleWithFixedDelay (Runnable command, long delay, long period, TimeUnit timeUnit) {
SCHEDULER.scheduleWithFixedDelay(command, delay, period, timeUnit);
}
private static class ScheduleHandlerThreadFactory implements ThreadFactory {
private int count = 1;
private String prefixString = null;
public ScheduleHandlerThreadFactory (String prefix) {
this.prefixString = prefix;
}
@Override
public Thread newThread(Runnable r) {
log.debug("Create thread #" + this.count);
return new Thread(handlingGroup, r, this.prefixString + "-" + this.count++);
}
}
}
在完全沒有外在因素干擾的狀況下，我的預設結果是認為假設任務 1 在 3:00:00 執行一次，下一次執行應該會在 3:01:00。
而程式的執行結果如下～
2014-02-19 17:01:24.420 | DEBUG | Main > Initial scheduler. 2014-02-19 17:01:24.425 | DEBUG | Main > Sleep. 2014-02-19 17:01:26.425 | DEBUG | Main > Set schedule #1. 2014-02-19 17:01:26.427 | DEBUG | Scheduler > Create thread #1 2014-02-19 17:01:26.427 | DEBUG | Main > Set schedule #2. 2014-02-19 17:01:26.428 | DEBUG | Threads-1 > Job #1 is running at 05:01:26 2014-02-19 17:01:36.428 | DEBUG | Threads-1 > Job #2 is running at 05:01:36 2014-02-19 17:02:36.427 | DEBUG | Threads-1 > Job #1 is running at 05:02:36 2014-02-19 17:02:46.427 | DEBUG | Threads-1 > Job #2 is running at 05:02:46 2014-02-19 17:03:46.426 | DEBUG | Threads-1 > Job #1 is running at 05:03:46 2014-02-19 17:03:56.426 | DEBUG | Threads-1 > Job #2 is running at 05:03:56
從結果可以看出，ExecutorService 的排程其實是依據上次執行結束的時間，加上設定的時間區間來決定下次開始執行的時間
同時就算開始執行的時間到了，也會因為 Thread Pool 滿載的關係而導致開始執行的時間被延後
綜合來說，可以表示 ExecutorService 的任務基本上是無法預測執行的時間的，而且任務越多、距離初始化的時間越久，任務的實際執行時間會跟預期的時間差距越遠。
就上面的結論來看，如果需要的排程是時間要比較精準，那就不適合利用 scheduleWithFixedDelay() 來定時執行
反而應該用每次設定只執行一次的 on-shot 版的函式 schedule() 來觸發執行
同時在 Runnable 執行結束時手動放入下一次 on-shot 執行的排程進去。
而如果一點誤差都沒有，那麼建議是自行產生自己的 ExecutorService，並依照上述的 on-shot 的方式每次執行完，自己幫自己設定下次的執行時間
不要讓排程跟其他任務共用同一個 Thread Pool，因為會有機會造成任務延遲，導致實際執行時間產生誤差。
沒有留言:
張貼留言