最近發現一個程序裡打出來的日誌裡時區不一樣，一個是UTC時間,2018-09-12 10:48:12.278,一個是北京時間2018-09-12 18:48:15.453。北京時間的是log4j輸出的,UTC時間的是我們自己輸出的，我們自己的時間字串來源是大概如下兩行程式碼:

SimpleDateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
String dateString = dateFormat.format(new Date());

Log4j的時間是怎麼來的呢?
以log4j1為例,有如下呼叫關係 
RollingFileAppender.subAppend()->WriterAppender.subAppend()-> PatternLayout.format() -> BridgePatternConverter.format() -> FormattingInfo.format() -> DatePatternConverter.format() -> CachedDateFormat.format()
那CachedDateFormat是怎麼初始化的呢? DatePatternConverter 構造方法中可以看到

    if ((options != null) && (options.length > 1)) {
      TimeZone tz = TimeZone.getTimeZone((String) options[1]);
      simpleFormat.setTimeZone(tz);
    } else {
      simpleFormat = new DefaultZoneDateFormat(simpleFormat);
    }
    df = new CachedDateFormat(simpleFormat, maximumCacheValidity);
 

可以在log4j.xml中指定時區(比如"%d{ISO8601}{GMT-4}  %m%n"),如果不指定則是使用作業系統預設時區

log4j2中則是
RollingFileAppender.append() -> AbstractOutputStreamAppender.append() -> AbstractOutputStreamAppender.tryAppend() -> AbstractOutputStreamAppender.writeByteArrayToManager() -> AbstractStringLayout.toByteArray() -> PatternLayout.toSerializable() -> PatternLayout.PatternSerializer.toSerializable()->PatternLayout.PatternSerializer.toSerializable() -> PatternFormatter.format() —> DatePatternConverter.format()—> DatePatternConverter.formatWithoutAllocation()
在DatePatternConverter 類的 createNonFixedFormatter 可以看到

        TimeZone tz = null;
        if (options.length > 1 && options[1] != null) {
            tz = TimeZone.getTimeZone(options[1]);
        }

        try {
            final FastDateFormat tempFormat = FastDateFormat.getInstance(pattern, tz);
            return new PatternFormatter(tempFormat);

在不設定tz的情況下 timeZone = TimeZone.getDefault();
FormatCache 來cache每種型別;
不論log4j1還是log4j2,可以確定如下幾點:
1.如果不配置時區,都是使用預設時區
2.時區初始化好了就不會變化
3.一個Appender物件一種格式化物件(log4j2是FastDateFormat物件;log4j1是DefaultZoneDateFormat)

回到問題,我們自己的和logj對時間的時區處理都是基於TimeZone.getDefault()來的,為什麼會一個是UTC一個是CST呢？
後來定位到是因為我們自己自己懶載入的bean裡有靜態塊
TimeZone.setDefault(TimeZone.getTimeZone("UTC"));
那麼問題就清楚了,log4j的LOGGER和Appender物件初始化時先讀取了作業系統的CST時間,然後物件一直沒變；然後我們程式碼修改了時區,導致我們程式碼打出來的時間為UTC。