Java - ThreadLocal 實際應用

By sunwc 2023-03-15 Experience

有關如何使用 ThreadLocal 確保 Thread-safety,可以參考我的另一篇文章 Java - ThreadLocal 類的使用

筆者曾經在不了解 ThreadLocal 類的情況下,錯用 ThreadLocal 客製Log物件的工具類,後來理解 ThreadLocal 運作原理後,在這裡特別記錄下來

客製 LogBox 類

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 類使用情境

情境一、這個 LogBox 類實際上是可以應用在 Filter interface

透過建立一個客製類實作 Filter 並實現 doFilter 方法,一開始透過 createCurrentThreadLogBox(title) 建立屬於該 request (該執行緒) 的 ThreadLocal<LogBox> 物件,中間還可以從 request 中取得 requestURI、requestParams 並取得 response 等資訊都加入 ThreadLocal<LogBox>等程式從controller層回到 doFilterremoveLogBoxAndGetLog() 清除當前執行緒 ThreadLocal<LogBox>

因為有上面提及的這層操作,因此在SpringBoot framework 的 Controller 或 Service 層的 function 中,就只需要getCurrentThreadLogBox() 取得當前執行緒的 LogBox,並將當前API、業務邏輯所需顯示的 log 內容,透過 log.info("xxxx"), log.error(exeption message),… 將不同層級訊息加到 LogBox 中

圖片來源


情境二、這個 LogBox 類實際上是可以應用在 quartz 排程

透過建立一個客製類繼承 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) ,才解決了問題

例子

  • quartz入口類
@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);
      }
    }
  }
}
  • quartz入口類呼叫ScheduleService類方法
  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),這樣就沒問題啦!