爲什麼Google App Engine日誌中的請求時間與Appstats中的請求時間不同？

我在Google App Engine的基於Java的HDR應用程序上運行Appstats。現在我對實際的App Engine請求日誌和Appstats日誌之間的時間差異感到困惑。這段時間似乎有相當的漂移。解釋我的意思是我帶了一些截圖。他們都來自同一個請求。爲什麼Google App Engine日誌中的請求時間與Appstats中的請求時間不同？

這一個是從App Engine的請求日誌：

而這一次是從將Appstats相同的請求：

下面是測量一個列表我能夠提取：

Log Timestamp   10:10:33.156 
Log "Total"     147ms 
Log "ms"      147ms 
Log "cpu_ms"     86ms 

Appstats Timestamp  10:10:33.072 
Appstats "Grand Total"   39ms 
Appstats "real"     39ms 
Appstats "RPC Total"   20ms 
Appstats "api"     0ms 
Appstats "overhead"    0ms

正如你可以看到，有兩個在請求時間戳和運行時相當的差異：

Difference Log/AS Timestamps 84ms 
Difference Log/AS Total  108ms (377%)

順便說一句：雖然請求時間戳是不一樣的它仍然是相同的請求：我跟着鏈接將Appstats發佈到請求日誌中，並在未使用的測試應用程序上執行此測試，以便確保鏈接正確。

爲什麼Appstats告訴我我的請求需要39ms，而GAE請求日誌告訴我請求的時間長了3.8x（147ms）？爲什麼相同的請求有兩個不同的時間戳？

Thanksalot！

來源

2014-02-10 Holger

將appstats掛鉤到代碼中，在您的代碼（appstats）被調用之前以及在appstats退出之後還會有一段時間。記住appengine不會流到客戶端，但所有的輸出都是到某種類型的緩衝區，然後傳遞給appengine基礎架構進行傳送。

請求的時間表將會像

開始的請求（開始你在日誌中看到的時間）將Appstats覆蓋的代碼
將Appstats年底覆蓋的代碼
最終的
啓動迴應發送（總持續時間）

這將是有趣的，看看多少1和4將平均，和th可能取決於運行時間。

哦，將Appstats本身會產生一定的開銷，這會不會被測量的Appstats，包括啓動，並在結束清理，這在1和2

來源

2014-02-10 11:27:13

您好添貢獻的時候了！非常感謝您的回覆。我明白，在Appstats可以啓動前，每個請求都會有一些「封閉」開銷。有趣的是，Appstats時間戳在請求日誌時間戳之前，這表明日誌時間戳不是請求的開始？ – Holger

或者，日誌記錄系統開始請求時間不是來自同一時鐘，而是來自前端基礎設施 - 只是一個猜測。 –

實際上，如果您考慮它，日誌條目來自日誌服務，時間戳將來自日誌服務。日誌服務時鐘可能與您的實例時鐘不同（實例時鐘可能會彼此稍微偏離）。要測試此理論，請記錄您創建的時間戳，並查看它是否與日誌條目時間戳匹配。 –

爲什麼Google App Engine日誌中的請求時間與Appstats中的請求時間不同？

回答

相關問題