我有一個客戶端軟體，它呼叫安裝在同一台機器上的apache httpd 伺服器。在呼叫 apache 日誌之前記錄一個日誌條目：
2011-11-23 13:27:43,777 | 8323|1381677376 | root | DEBUG | Calling http://mydomain.com/api/project/325/postings/add_and_remove_labels
正如您所看到的，通話是在當地時間 13:27:43 撥打的。網域mydomain.com解析同一台機器的外部IP。
但是，當我查看 access.log 檔案時，我說日誌條目的時間戳 [1] 晚於 5 秒：
[23/Nov/2011:13:27:48 +0100] "GET /api/project/325/postings/add_and_remove_labels
這是一個以守護程序模式運行的 mod_wsgi 基本伺服器，但我不確定它是否相關（如果請求在 apache 級別，則時間戳記應該是開始）。
我怎樣才能最好地找出這 5 秒的來源？
乾杯，波阿斯
澄清：[1] - 時間戳是請求的時間開始了。確實，請求結束時條目會寫入日誌，但時間是請求開始的時間。
答案1
這是因為訪問日誌寫在他結尾請求的內容，而不是開頭。因此，如果您在 12:00 發出請求，並且需要一分鐘才能完成，則直到 12:01 才會寫入該條目。事實上，它可以包含傳輸的位元組數之類的內容，這就是這一點的明確指標。
您還可以執行從一台主機到另一台主機的追蹤路由，以查看它是否真正收到請求 - 如果您在路由過程中看到延遲，則表示問題的根源所在。
答案2
需要檢查兩件事：
- 在伺服器上解析名稱 mydomain.com 的時間（在註釋中歸功於 TokenMacGuy）
- 請求完成後寫入日誌時腳本的執行時間