有關如何使用 ThreadLocal 確保 Thread-safety,可以參考我的另一篇文章 Java - ThreadLocal 類的使用
筆者曾經在不了解 ThreadLocal 類的情況下,錯用 ThreadLocal 客製Log物件的工具類,後來理解 ThreadLocal 運作原理後,在這裡特別記錄下來
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.LinkedList;
import java.util.List;
public class LogBox {
private static final ThreadLocal<LogBox> currentThreadLogBox = new ThreadLocal<>();
private static final ThreadLocal<SimpleDateFormat> currentThreadSDF = new ThreadLocal<>();
private final String title;
private final static String timeType = "yyyy-MM-dd HH:mm:ss.SSS";
private final List<String> logMsgList = new LinkedList<>();
public LogBox(String title) {
this.title = title;
}
/**
* 日誌訊息層級
*/
public enum MessageType {
MESSAGE, DEBUG, WARNING, ERROR
}
/**
* 建立當前執行緒logBox
* @param title
* @return
*/
public static LogBox createCurrentThreadLogBox(String title) {
LogBox logBox = new LogBox(title);
currentThreadLogBox.set(logBox);
return logBox;
}
/**
* 取得當前執行緒logBox
* 當某個request流程跨function時
* 則可以使用同一個logBox
* @return
*/
public static LogBox getCurrentThreadLogBox() {
if (currentThreadLogBox.get() == null) {
createCurrentThreadLogBox("title unset");
}
return currentThreadLogBox.get();
}
/**
* 清除當前執行緒LogBox
* 清除當前執行緒SimpleDateTimeFormat
* 並取得log字串
* @return
*/
public String removeLogBoxAndGetLog() {
removeCurrentThreadSDF();
currentThreadLogBox.remove();
StringBuilder sb = new StringBuilder();
if (logMsgList.size() > 0) {
sb.append("Log Title : ").append(title);
logMsgList.forEach(eachLine -> {
sb.append("\n").append("\t").append(eachLine);
});
}
sb.append("\n").append("=========================================================");
return sb.toString();
}
/**
* 簡略示意客製添加 info 層級 log 訊息
* @param msg
*/
public void info(String msg) {
SimpleDateFormat simpleDateFormat = currentThreadSDF.get();
String now = simpleDateFormat.format(new Date());
msg = String.format("[%s] '%s' %s", MessageType.MESSAGE, now, msg);
logMsgList.add(msg);
}
// 接收 debug、warn、error 等 log 訊息 function......
/**
* 建立當前執行緒SimpleDateFormat
* @return
*/
public static SimpleDateFormat createCurrentThreadSDF() {
SimpleDateFormat sdf = new SimpleDateFormat(timeType);
currentThreadSDF.set(sdf);
return sdf;
}
/**
* 取得當前執行緒SimpleDateFormat
* @return
*/
public static SimpleDateFormat getCurrentThreadSDF() {
if (currentThreadSDF.get() == null) {
createCurrentThreadSDF();
}
return currentThreadSDF.get();
}
/**
* 清除當前執行緒SimpleDateFormat
*/
public void removeCurrentThreadSDF() {
currentThreadSDF.remove();
}
}
LogBox 類使用情境
透過建立一個客製類實作 Filter 並實現 doFilter 方法,一開始透過 createCurrentThreadLogBox(title)
建立屬於該 request (該執行緒) 的 ThreadLocal<LogBox>
物件,中間還可以從 request 中取得 requestURI、requestParams 並取得 response 等資訊都加入 ThreadLocal<LogBox>
,等程式從controller層回到 doFilter 再 removeLogBoxAndGetLog()
清除當前執行緒 ThreadLocal<LogBox>
因為有上面提及的這層操作,因此在SpringBoot framework 的 Controller 或 Service 層的 function 中,就只需要getCurrentThreadLogBox()
取得當前執行緒的 LogBox,並將當前API、業務邏輯所需顯示的 log 內容,透過 log.info("xxxx")
, log.error(exeption message)
,… 將不同層級訊息加到 LogBox 中
透過建立一個客製類繼承 QuartzJobBean 並覆寫 executeInternal 方法,一開始透過 createCurrentThreadLogBox(title)
建立屬於該排程 (該執行緒) 的 ThreadLocal<LogBox>
物件;不過,此方法可能會再存取 ScheduleService 類的方法,因此在 ScheduleService 層就只需要 getCurrentThreadLogBox()
取得當前執行緒的 LogBox ,並添加業務邏輯所需顯示的 log 內容,透過 log.info("xxxx")
, log.error(exeption message)
,… 將不同層級訊息加到 LogBox 中,等排程快結束時程式回到 executeInternal 方法,再 removeLogBoxAndGetLog()
清除當前執行緒 ThreadLocal<LogBox>
筆者在理解 ThreadLocal 後,但是卻在下面例子的當程式走到
callTransferLimitUpPer30Mins()
內部時,該 function 的 log 都印不出來;
在 callTransferLimitUpPer30Mins()
function 的內部,才 getCurrentThreadLogBox()
取得當前執行緒的 LogBox,最後才發現這個坑是跟 ExecutorService interface 有關;
將 LogBox 物件當作傳參送到 callTransferLimitUpPer30Mins(logBox)
,才解決了問題
@Slf4j
@DisallowConcurrentExecution
public class RaiseupTransferLimitJob extends QuartzJobBean {
@Autowired
CancelRaiseupLimitTask cancelRaiseupLimitTask;
public static final String TASK_NAME = QuartzTaskNameConstants.raiseupTransferLimt;
public static final String PROP_NAME = "quartz.findBeforeSystemTimeLessThan1Day";
public RaiseupTransferLimitJob() {
QuartzJobService.descriptionMap.put(TASK_NAME, "re-send raiseupTransferLimit");
QuartzJobService.taskDisplayNameMap.put(TASK_NAME, TASK_NAME);
}
@Override
public void executeInternal(JobExecutionContext jobExecutionContext) {
String logTitle = new Exception().getStackTrace()[0].getClassName()+"."+new Exception().getStackTrace()[0].getMethodName();
LogBox logBox = LogBox.createCurrentThreadLogBox(logTitle);
logBox.info("start running callTransferLimitUpPer30Mins");
try {
cancelRaiseupLimitTask.cancelTaskPer60MINS();
} catch (Exception e) {
logBox.error(e);
} finally {
logBox.info("end run callTransferLimitUpPer30Mins");
String logString = logBox.removeLogBoxAndGetLog();
if (logString != null && logString.trim().length() > 0) {
log.info(logString);
}
}
}
}
public void cancelTaskPer60MINS() throws Exception {
LogBox logBox = LogBox.getThreadLocalLogBox();
ExecutorService executor = Executors.newSingleThreadExecutor();
Future<String> future = executor.submit(() -> {
// 需求是若排程有timeout情況產生,單一排程至多執行60分鐘
callTransferLimitUpPer30Mins(logBox); // 排程業務邏輯
logBox.info("callTransferLimitUpPer30Mins is completed!");
return "Ready!";
});
try {
logBox.info("Every 60 minutes is started..");
// 設置最大等待時間
logBox.info(future.get(60, TimeUnit.MINUTES));
logBox.info("Every 60 minutes is finished!");
} catch (TimeoutException e) {
// 允許取消正在運行的執行緒——以拋出異常的方式中斷
future.cancel(true);
logBox.info("callTransferLimitUpPer30Mins is terminated!");
}
executor.shutdownNow();
logBox.info("cancelTaskPer60MINS shutdown now");
}
關於 log 印不出來,我的想法是 原來在主執行緒的 LogBox ,與 Executors 建立的單一執行緒裡的 LogBox 彼此之間是不互相影響的;但是只有主執行緒的 LogBox 可以印出 log (因為最後有 removeLogBoxAndGetLog()
),所以我就必須將主執行緒產生出來的 LogBox 當作傳參送入 callTransferLimitUpPer30Mins(logBox)
,這樣就沒問題啦!