為什麼我的 Apache 訪問日誌時間戳有時會倒退？

我注意到在我的 Apache 日誌（實際上是 Oracle 的品牌 HTTP 伺服器，它實際上是 Apache）中，行的時間戳有時會下降，而不是上升。這是一個例子：

1.2.3.4 - - [16/Dec/2014:**13:22:46** +1100] "POST /cas/v1/tickets/TGT-4830717-K5FWqTeJfIajdbae0Zbc1hqSOREWG92fybtLKYtdufKve16Uou-cas-1.2.3.4-2 HTTP/1.1" 200 60 
1.2.3.4 - - [16/Dec/2014:**13:12:42** +1100] "POST /self-service/api/account/verification/residential HTTP/1.1" 400 0 
1.2.3.4 - - [16/Dec/2014:13:12:15 +1100] "GET /self-service/api/accounts/38909 HTTP/1.1" 404 0 
1.2.3.4 - - [16/Dec/2014:13:20:46 +1100] "GET /self-service/oamCallback?authn_try_count=1&contextType=external&username=string&contextValue=%2Foam&password=sercure_string&challenge_url=https%3A%2F%2Fwww.xxx.com.au%2Fmyaccount%2FoamCallback&request_id=-3108004070152329208&p_error_code=OAM-2&p_error_codes_list=OAM-2&locale=en_US&resource_url=https%253A%252F%252Fwww.xxx.com.au%252Fmyaccount%252Fapi%252Fprofile HTTP/1.1" 401 70 
1.2.3.4 - - [16/Dec/2014:13:22:46 +1100] "GET /cas/proxyValidate?&ticket=ST-4830713-csoZibAECToKVXXYTIVS-cas-1.2.3.4-2&service=http%3A%2F%2F1.2.3.4%3A7002%2Fservlet%2FREST%2Fsites%2FxxxQuotes%2Ftypes%2FPage%2Fassets%2F1343354161974 HTTP/1.1" 200 704 

看看 2 號線的時間比 1 號線早了近 10 分鐘？

這正常嗎？

或者如果沒有，知道是什麼原因造成的嗎？

日誌消息中的時間表示收到請求的時間。但是，每個請求僅在處理完成後才被記錄。

這意味著如果某些請求需要很長時間才能處理，它們可能會出現亂序。%D我發現包含在 中很有用LogFormat，這樣我就可以看到每個請求花費了多少微秒。

如果你的日誌中有這個，你就會知道第二個請求是否確實需要 10 分鐘來處理。

不，從它們應該單調增長的意義上說，這不是“正常的”。

但有時它可能會發生，即使您的系統中沒有任何錯誤：

1. 13:22，系統日期改回13:12，可能是因為你的ntp同步惡魔
2. 有多個 apache 程序，它們正在寫入同一個日誌文件。如果第一個程序收到請求，但它已超時，則它的條目可能只有在它們超時後才被寫入日誌。在此期間，其他子程序可以正常工作。

如果偏差是圓形的（例如，正好 10 分鐘），那麼 (2) 的可能性更大，因為您的系統時鐘的每日延遲可能不會那麼圓形。

如果它經常發生（更頻繁地因為您的時鐘同步守護程序設置時鐘），它是否也是對（2）的投票。

但是在 (1) 的情況下，時鐘同步工具（可能是您系統上的 ntp）肯定會記錄下來。深入日誌以查找是否發生。

引用自：https://serverfault.com/questions/661116