深入查看日誌

大學畢業後我便加入了 Amazon,當時首先參加的一項入職培訓是,啟動 amazon.com Web 伺服器並在我的開發人員桌面上執行。我第一次嘗試操作時並沒有做對,但也不確定我做錯了什麼。一位樂於助人的同事建議我查看日誌,看看有什麼問題。他說,要這樣做的話,我應當「儲存日誌檔案」。 我確信他們在對我玩些惡作劇,或者對不懂 cat 的我開玩笑。我在大學只用過 Linux 進行編譯,使用源代碼控制,以及使用文字編輯器。因此,我不知道 “cat” 實際上是將檔案列印至終端機的命令,可以將其輸入另一個程式來尋找模式。

我的同事向我介紹了 cat、grep、sed 和 awk 等工具。憑藉此全新的工具集,我就可以深入查看開發人員桌面 amazon.com 的 Web 伺服器日誌。Web 伺服器應用程式已經過檢測,可以將各種實用的資訊傳送至其日誌中。這讓我能夠查看缺少的組態,這些組態阻止了 Web 伺服器的啟動,顯示可能崩潰的位置,或指示無法與下游服務進行通訊的位置。該網站由許多活動元件組成,對我而言,從一開始其本質上就是一個黑匣子。然而,在深入研究系統之後,我了解到如何僅透過查看檢測輸出,來確定伺服器的工作方式,以及如何與其相依性互動。

為什麼要進行檢測

多年來,我在 Amazon 各個團隊開展工作,我發檢測是我和 Amazon 其他同事研究系統運作方式的無價之寶。而檢測不僅對了解系統有用,它的用處遠不止於此。它是 Amazon 營運文化的核心。出色的檢測有助於我們看到為客戶提供的體驗。
 
對營運績效的關注貫穿於整個公司。在與 amazon.com 相關的服務中,延遲增加會導致不良的購物體驗,從而降低轉化率。對於使用 AWS 的客戶,他們依賴於 AWS 服務的高可用性和低延遲。
 
在 Amazon,我們不僅僅是考慮平均延遲。我們 甚至更密切地關注延遲異常值,例如 99.9% 和 99.99%。這是因為,若 1,000 或 10,000 個請求中有一個請求較慢,那仍然是糟糕的體驗。我們發現,當我們減少系統中高百分比延遲時,我們的努力會產生減少中值延遲的副效應。相比之下,我們發現當減少中值延遲時,這會減少較高百分比延遲的頻率。
 
我們關注高百分比延遲的另一個原因是,一項服務中的高延遲可能會對其他服務產生事半功倍的效果。Amazon 是建立在以服務為基礎的架構上。許多服務相互協作以完成某些任務,例如在 amazon.com 上呈現網頁。因此,深入叫用鏈結服務延遲的增加,即使在高百分比情況下增加,亦會對最終使用者經歷的延遲產生很大的連鎖反應。
 
Amazon 的大型系統由許多合作服務組成。每項服務都由單一團隊開發和營運 (大型「服務」由幕後的多項服務或元件組成)。擁有服務的團隊稱為 服務擁有者。無論該團隊成員是軟體開發人員、網路工程師、經理還是其他任何角色,每位成員都像服務的擁有者和營運者一樣。作為擁有者,團隊為所有相關服務的營運績效設定目標。我們還將確保我們對服務營運具有可視性,以確保能夠實現這些目標,處理出現的任何問題,並在下一年為自己設定更高的目標。若要設定目標並獲得可視性,團隊必須對系統進行檢測。
檢測還讓我們能夠在戰術上偵測並回應操作事件。
 
檢測將資料饋入操作儀表板,以便操作人員可以查看即時指標。此外,還會將資料饋入警報,當系統以異常方式運作時,警報會觸發並讓操作人員介入。操作人員利用檢測的詳細輸出,快速診斷發生問題的原因。我們可以藉此緩解問題,稍後再回來防止該問題再次發生。若沒有對整個代碼進行良好的檢測,我們就會將寶貴的時間浪費在診斷問題上。

需要量測哪些方面

為了按照我們在可用性和延遲方面的高標準來運作服務,我們作為服務擁有者需要量測系統的行為。

為了獲得必要的遙測,服務擁有者可從多個地方量測營運績效,以從多個角度了解端對端的行為方式。即使在簡單的架構中,這也很複雜。考慮客戶透過負載平衡器叫用的服務:該服務與遠端快取和遠端資料庫對話。我們希望每個元件都發出有關其行為的指標。我們還需要有關每個元件如何感知其他元件行為的指標。將所有這些方面的指標匯總在一起後,服務擁有者便能快速找到問題的來源,並深入查找原因。

許多 AWS 服務會自動提供有關您資源的營運洞見。例如,Amazon DynamoDB 提供有關量測服務成功率、錯誤率、延遲的 Amazon CloudWatch 指標。然而,當我們建構使用這些服務的系統時,我們需要對我們的系統行為有更多的了解。檢測需要使用明確的代碼來記錄任務花費的時間,執行某些代碼路徑的頻率,有關任務正在執行的中繼資料,以及任務的哪些部分成功或失敗。若團隊不新增顯式工具,則會被迫將其自身服務作為黑匣子運作。

例如,若我們實作了透過產品 ID 擷取產品資訊的服務 API 操作,則代碼可能類似於以下範例。這段代碼在本機快取中查找產品資訊,然後在遠端快取中查找資料庫:

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // check our local cache
  ProductInfo info = localCache.get(request.getProductId());
  
  // check the remote cache if we didn't find it in the local cache
  if (info == null) {
    info = remoteCache.get(request.getProductId());
	
	localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    info = db.query(request.getProductId());
	
	localCache.put(info);
	remoteCache.put(info);
  }
  
  return info;
}

若我正在使用此服務,則需要對代碼進行大量的檢測,才能了解其在生產中的行為。我需要能夠對失敗或緩慢的請求進行疑難排解,並監控不同的相依性規模不足或行為異常的趨勢和跡象。以下是同樣的代碼並帶有注釋,其中包含我能夠解答的有關整個生產系統,或針對特定請求的問題:

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // Which product are we looking up?
  // Who called the API? What product category is this in?

  // Did we find the item in the local cache?
  ProductInfo info = localCache.get(request.getProductId());
  
  if (info == null) {
    // Was the item in the remote cache?
    // How long did it take to read from the remote cache?
    // How long did it take to deserialize the object from the cache?
    info = remoteCache.get(request.getProductId());
	
    // How full is the local cache?
    localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    // How long did the database query take?
    // Did the query succeed? 
    // If it failed, is it because it timed out? Or was it an invalid query? Did we lose our database connection?
    // If it timed out, was our connection pool full? Did we fail to connect to the database? Or was it just slow to respond?
    info = db.query(request.getProductId());
	
    // How long did populating the caches take? 
    // Were they full and did they evict other items? 
    localCache.put(info);
    remoteCache.put(info);
  }
  
  // How big was this product info object? 
  return info;
}

解答所有這些問題 (及更多問題) 的代碼比實際的業務邏輯要長得多。某些庫可協助減少檢測代碼的數量,但開發人員仍然必須詢問有關庫的必要可視性問題,然後開發人員必須有意識地寫入檢測中。

對流經分散式系統的請求進行疑難排解時,若僅基於一次互動來查看該請求,可能很難了解發生了什麼。為了解決這個難題,我們發現,將所有這些系統的所有指標匯總在一起很有幫助。在執行該操作之前,必須對每項服務進行檢測,以記錄每項任務的跟踪 ID,並將該跟踪 ID 傳播給在該任務上進行協作的每項其他服務。可以視需要在事後,或使用 AWS X-Ray 之類的服務,近乎即時地針對給定的跟踪 ID 跨系統收集工具。

向下鑽研

檢測支援在多個級別進行疑難排解,從瀏覽指標以查看是否有任何異常細微到無法觸發警報,到進行調查以找出那些異常的原因。

在最高級別上,檢測會匯總為指標,這些指標可以觸發警報,並顯示在儀表板上。這些匯總指標讓營運者可以監控總體請求率、服務叫用延遲和錯誤率。這些警報和指標讓我們知道應調查哪些異常或變更。

看到異常後,我們需要弄清楚為什麼會發生這種異常。要解答該問題,我們依靠透過更多檢測實現的指標。透過檢測執行請求各個部分所花費的時間,我們可以看到處理的哪個部分比正常情況慢,或者更頻繁地觸發錯誤。

雖然匯總計時器和指標可以協助我們排除原因或突出調查範圍,但它們並非總是提供完整的解釋。例如,我們也許能夠從指標中得知錯誤是來自特定的 API 操作,但指標可能無法揭示有關該操作失敗原因的足夠細節。此時,我們需要查看該時間窗口內,服務發出的原始詳細日誌資料。原始日誌隨後將顯示問題的來源,正在發生的特定錯誤,或觸發某些邊緣情況的請求的特定方面。

我們的檢測方式

檢測需要編碼。這意味著在實作新功能時,我們需要花一些時間新增額外的代碼來指示發生的情況,成功還是失敗,以及花費了多長時間。由於檢測是一種常見的編碼任務,因此,Amazon 憑藉多年的經驗形成了適用於常見模式的實務:常見檢測庫標準化,以及結構化日誌型指標報告標準化。

得益於指標檢測庫的標準化,庫的編撰者可向其庫的取用者提供有關庫如何運作的洞見。例如,常用的 HTTP 用戶端與這些公共庫整合在一起,因此,若服務團隊實作對另一項服務的雲端叫用,則它們會自動獲取有關這些叫用的檢測資訊。

當檢測到應用程式執行並工作時,產生的遙測資料將被寫入結構化日誌文件。通常,無論是 HTTP 服務請求,還是從佇列中提取訊息,它都作為每個「工作單元」的一個日誌項目發出。

在 Amazon,該應用程式中的量測值未匯總,並且偶爾會排清到指標匯總系統。每件工作的所有計時器和計數器都記錄在日誌檔案中。此後,日誌由其他系統根據情況進行處理,並計算匯總指標。這樣一來,我們最終獲得了從高級別匯總操作指標,到請求級詳細疑難排解資料的一應內容,所有這些只需使用單一的檢測代碼方法即可。在 Amazon,我們先記錄,再產生匯總指標。

透過日誌記錄進行檢測

我們最常檢測的服務是發出兩種類型的日誌資料:請求資料和偵錯資料。請求日誌資料通常表示為,每個工作單元的單一結構化日誌項目。該資料包含有關請求和發出請求者的屬性、請求的目的、事情發生頻率的計數器,以及事情花費時長的計時器。請求日誌用作稽核日誌,以及對服務中發生的所有事件的跟踪。偵錯資料包括應用程式發出的任何偵錯行的非結構化或鬆散結構的資料。通常,這些是非結構化日誌項目,例如 Log4j 錯誤或警告日誌行。在 Amazon,這兩類資料通常會被發送至單獨的日誌檔案,部分是因為歷史原因,還因為使用同質性日誌項目格式進行日誌分析會很方便。

CloudWatch Logs Agent 之類的代理程式會即時處理兩類日誌資料,並將日誌發送至 CloudWatch Logs。相應地,CloudWatch Logs 也幾乎即時地產生有關服務的匯總指標。Amazon CloudWatch Alarms 讀取這些聚合指標並觸發警報。

雖然為每項請求記錄許多詳細資訊可能會很昂貴,但在 Amazon 我們發現這樣做非常重要。畢竟,我們需要調查可用性問題、延遲尖峰和客戶報告的問題。若沒有詳細的日誌,我們將無法為客戶提供答案,也無法改善其服務。 

深入研究詳細資訊

監控和警報的主題非常廣泛。在本文中,我們不會涉及以下主題︰設定和調整警報閾值、整理操作儀表板、從伺服器端和用戶端量測效能、持續執行 “canary” 應用程式,以及選擇用於匯總指標和分析日誌的適當系統。

本文將重點講述檢測應用程式的需求,以產生正確的原始量測資料。我們將介紹 Amazon 團隊在檢測其應用程式時盡量包括 (或避免) 的事情。

請求日誌最佳實務

在這個部分,我將講述隨著時間的推移,在 Amazon 學到的有關記錄「每個工作單元」結構化資料的良好習慣。滿足這些條件的日誌包含顯示事物發生頻率的計數器,顯示事物花費時長的計時器,以及有關每個工作單元中繼資料的屬性。

我們的記錄方式

針對每個工作單元發出一個請求日誌項目。 工作單元通常是我們的服務收到的請求,或從佇列中提取的訊息。我們針對服務收到的每項請求,編寫一個服務日誌項目。我們不會合併多個工作單元。這樣,當我們對失敗的請求進行疑難排解時,我們只需查看單一日誌項目。此項目包含有關請求的相關輸入參數,只需在一處,即可查看請求的內容、有關發起人的訊息,以及所有計時和計數資訊。
針對給定請求發出的請求日誌項目不超過一個。 在無封鎖服務實作中,針對處理管道中的每個階段,發出單獨的日誌項目似乎很方便。取而代之的是,透過在管道各個階段之間,將控點連接至周圍的單一「指標物件」,然後在所有階段完成之後,將指標作為一個單元進行序列化,我們能夠在這些系統的疑難排解方面取得更大的成功。若每個工作單元具有多個日誌項目,則日誌分析會更加困難,且由於乘法器,本已昂貴的日誌記錄開銷也會增大。若我們在撰寫新的無封鎖服務,則要設法預先規劃指標記錄生命週期,因為以後很難重構和修復。
將長期執行的任務分為多個日誌項目。 與之前的建議相反,若我們有長期執行、數分鐘或數小時工作流程的類似任務,我們可能決定定期發出單獨的日誌項目,以便確定是否取得進展,或確定在何處放緩。
在進行驗證之類的操作之前,記錄有關請求的詳細資訊。 我們發現,對於疑難排解和稽核日誌記錄而言,記錄有關該請求的足夠資訊非常重要,這樣我們才能知道它設法要完成的任務。我們還發現,透過驗證,身分驗證或節流邏輯來拒絕請求之前,儘早記錄該資訊很重要。若我們要記錄傳入請求中的資訊,請確保在記錄輸入之前先處理輸入 (編碼、逸出和截斷)。例如,發起人傳入一個請求時,我們不想在服務日誌項目中包含長度為 1 MB 的字串。這樣做會有填滿磁碟空間的風險,並且花費超過日誌儲存預期。處理的另一個範例是,篩選掉與日誌格式相關的 ASCII 控制字元或逸出序列。若發起人傳遞了自己的服務日誌項目,並且能將其註入我們的日誌,則可能會造成混淆! 另請參閱﹔https://xkcd.com/327/
規劃一種記錄詳細程度的方法。 對於某類問題的疑難排解,日誌沒有關於問題請求的足夠詳細資訊,無法找出失敗的原因。服務中可能會提供該資訊,但資訊量可能太大,以致無法始終記錄日誌。針對這種情況,設置一個組態旋鈕可能會很實用。在調查問題時,透過轉動該旋鈕來臨時增加日誌的詳細程度。您可以轉動旋鈕來調整個別主機、個別用戶端,或者整個機群的取樣率。完成操作後,請務必將旋鈕調低。
確保指標名稱簡短 (但不要太短)。 Amazon 使用相同的服務日誌序列化已超過 15 年。在此序列化中,每個計數器和計時器名稱在每個服務日誌項目中以純文字重複。為了盡量減少日誌記錄開銷,我們使用簡短但清晰的計時器名稱。Amazon 開始採用基於二進位序列化通訊協定 (也稱為 Amazon Ion) 的新序列化格式。最後,務必選擇日誌分析工具可以理解的格式,這可讓序列化、還原序列化和儲存盡可能高效。
確保日誌量足夠大,能以最大的輸送量處理日誌。 我們以最大持續負載 (甚至過載) 測試服務數小時。我們需要確保當服務在處理多餘的流量時,該服務仍具有相應的資源,以產生新日誌項目的速率傳送離線日誌,否則磁碟最終會被填滿。此外,您還可以將日誌記錄設定在與根分區不同的檔案系統分區上發生,以免在遇到過多日誌記錄時系統崩潰。我們稍後將討論其他緩解措施,例如使用與輸送量成比例的動態取樣,但是無論採用何種策略,測試都是至關重要的。
考慮磁碟填滿時系統的行為。伺服器磁碟填滿後,將無法登入磁碟。發生這種情況時,服務應停止接受請求,還是丟棄日誌並繼續執行而不進行監控? 在不記錄日誌的情況下運作存在風險,因此,我們會測試系統,以確保偵測到磁碟將滿的伺服器。
同步時鐘。 眾所周知,分散式系統中的「時間」概念非常複雜。我們在分散式演算法中不依賴時鐘同步,但對理解日誌很有必要。我們執行 Chrony 或 ntpd 之類的精靈來進行時鐘同步,並監控伺服器的時鐘漂移。若要讓該操作更簡便,請參閱 Amazon Time Sync Service
發出零計數以獲取可用性指標。錯誤計數很有用,但錯誤百分比可能也有用。為了檢測「可用性百分比」指標,我們發現一種實用的策略是,在請求成功時發出 1,在請求失敗時發出 0。然後,得出指標的「平均」統計資料就是可用率。在其他情況下,刻意發出 0 資料點也可能會有所幫助。例如,若應用程式執行領導者選舉,當一個程序為領導者時定期發出 1,而當程序不是領導者時則定期發出 0,這有助於監控追蹤者的運作狀態。這樣,若程序停止發出 0,則更容易知道程序中的某項已損壞,並且若領導者發生了某些事情,無法對其進行接管。

我們記錄的內容

記錄所有相依項的可用性和延遲。 我們發現,這對於回答「為什麼請求速度太慢?」或「為什麼請求失敗?」的問題特別有用。 若沒有該日誌,我們只能將相依項圖與服務圖進行比較,並猜測相依服務延遲中的一個峰值是否導致我們正在調查的請求失敗。許多服務和用戶端框架會自動連接指標,但其他框架 (例如 AWS SDK) 則需要手動連接。
區分每次叫用、每個資源、每個狀態代碼等的相依性指標。 若我們在同一工作單元中多次與相同的相依項進行互動,則分別包含每次叫用的相關指標,並明確每個請求與之互動的資源。例如,叫用 Amazon DynamoDB 時,一些團隊發現包含每個資料表,以及每個錯誤代碼,甚至每個重試次數的計時和延遲指標很有幫助。這樣一來,因條件式檢查失敗而導致服務重試速度緩慢的情況便迎刃而解了。這些指標還揭示了,用戶端感知的延遲增加實際上是由於節流重試,或透過結果集進行編頁,而不是封包丟失或網路延遲所致。
存取時記錄記憶體佇列深度。 若請求與佇列進行互動,並且我們要從中拉出一個物件,或將某物件放入其中,我們會將目前的佇列深度記錄到所在的指標物件中。對於記憶體佇列,獲取這些資訊非常實惠。對於分散式佇列,可以免費使用此中繼資料來回應 API 叫用。此日誌記錄可協助尋找今後的待處理項目和延遲來源。此外,當我們從佇列中取出事物時,我們會量測事物在佇列中的持續時間。這意味著,在加入佇列之前,首先需要在訊息中新增自己的「加入佇列時間」指標。
針對每個錯誤原因新增一個額外的計數器。針對每個失敗的請求,考慮新增用於特定錯誤原因計數的代碼。應用程式日誌將包含導致失敗的訊息,以及詳細的例外狀況訊息。然而,我們還發現,這對於查看一段時間內指標中錯誤原因的趨勢也很有用,而不必在應用程式日誌中挖掘該資訊。從每個失敗例外狀況類別的單獨指標著手,會帶來很多便利。
按原因類別整理錯誤。 若將所有錯誤歸入同一指標,則該指標會變得複雜且無濟於事。至少,我們發現,將「用戶端故障」錯誤與「伺服器故障」錯誤區分開來很重要。 除此之外,進一步細分可能會有所幫助。例如,在 DynamoDB 中,若用戶端正在修改的項目與請求中的前提條件不相符,則用戶端可以發出條件式寫入請求,這會傳回錯誤。這些錯誤是有意為之,我們希望它們偶爾會發生。而來自用戶端的「無效請求」錯誤,很可能是我們需要修復的錯誤。
記錄有關工作單元的重要中繼資料。 在結構化的指標日誌中,我們還包含有關請求的足夠中繼資料,以便稍後可以確定請求來自誰,以及該請求嘗試執行什麼操作。這包括客戶在遇到問題時,希望我們在日誌中包含的中繼資料。例如,DynamoDB 記錄請求與之互動的資料表名稱,以及中繼資料,例如讀取操作是否為一致讀取。然而,它不會記錄正在儲存至資料庫,或從資料庫擷取的資料。
透過存取控制和加密來保護日誌。由於日誌包含一定程度的敏感資訊,因此我們採取各種措施來保護和保障該資料。這些措施包括對日誌加密,將存取權限於排解問題的操作人員,並定期對存取進行基準確定。
避免在日誌中放置過於敏感的資訊。 日誌需要包含一些敏感資訊才有用。在 Amazon,我們發現,日誌中必須包含足夠的資訊才能了解給定請求來自誰,這一點很重要,但我們會略過過於敏感的資訊,例如不影響路由或處理請求行為的請求參數。舉例來說,若代碼正在解析客戶訊息,並且解析失敗,則務必不要記錄承載以保護客戶隱私權,因為這可能會像以後排解疑難那樣難以解決。我們使用工具來決定能否以選擇加入的方式,而不是選擇退出的方式來記錄內容,以免以後記錄新增的敏感參數。Amazon API Gateway之類的服務允許設定要在其存取日誌中包含哪些資料,這是一種很好的選擇加入機制。
記錄跟踪 ID 並將其傳播至後端叫用中。給定的客戶請求可能會涉及許多合作服務。對於許多 AWS 請求,該服務可以少至兩或三項服務,而對於 amazon.com 請求,則服務要多得多。要弄清楚在對分散式系統進行疑難排解時發生的情況,我們在這些系統之間傳播相同的跟踪 ID,以便排列來自各種系統的日誌,從而查看失敗發生的位置。跟踪 ID 是一種中繼請求 ID,由作為工作單元起點的「前門」服務標記到分散式工作單元。AWS X-Ray 是一項服務,透過提供某些傳播來提供協助。我們發現,將跟踪傳遞至相依項很重要。在多執行緒環境中,框架代我們進行該傳播非常困難且容易出錯,因此,我們習慣於在方法簽名中傳遞跟踪 ID 和其他請求內容 (例如指標物件!)。我們還發現,在方法簽名中傳遞 Context 物件非常方便,因此,今後找到類似的傳遞模式時,我們不必進行重構。對於 AWS 團隊,這不僅涉及對我們的系統進行疑難排解,還涉及客戶對其系統進行疑難排解。客戶代表其客戶彼此互動時,依靠在 AWS 服務之間傳遞的 AWS X-Ray 進行跟踪。它要求我們在服務之間傳播客戶的 AWS X-Ray 跟踪 ID,以便他們可以獲得完整的跟踪資料。
根據狀態碼和大小記錄不同的延遲指標。錯誤通常很快傳回,如存取遭拒、節流和驗證錯誤回應。若用戶端開始以高速率節流,則延遲可能看起來不錯。要避免這種指標干擾,我們將單獨的計時器記錄為成功回應,並在儀表板和警報中關注該指標,而不是使用通用的「時間」指標。同樣,若根據輸入大小或回應大小,操作可能出現減慢,則我們會考慮發出已分類的延遲指標,如 SmallRequestLatency 和 LargeRequestLatency。此外,我們確保對請求和回應進行適當的限制,以避免複雜的掉電和失敗模式,但即使在經過精心設計的服務中,該指標儲存貯體技術也可以隔離客戶行為,並分散儀表板的干擾。

應用程式日誌最佳實務

這個部分介紹我們在 Amazon 上學到的有關記錄非結構化偵錯日誌資料的良好習慣。

確保應用程式日誌沒有垃圾郵件。 儘管在請求路徑上可能有 INFO 和 DEBUG 層級的日誌陳述式,以協助在測試環境中進行開發和偵錯,但我們還是考慮在生產環境中停用這些日誌層級。我們將服務日誌視為跟踪資訊的位置,而不是依賴應用程式日誌來獲取請求跟踪資訊,從而能夠輕鬆地產生指標,並查看一段時間內的總體趨勢。不過,這裡沒有非對即錯的規則。我們的方法是不斷檢閱日誌,以查看其是否過於複雜 (或不夠複雜),並隨時間的推移調整日誌層級。例如,當我們深入查看日誌時,經常會發現日誌陳述式過於複雜,或是我們希望擁有的指標。幸運的是,這些改進通常很容易實現,因此我們已經習慣於提交快速跟進的待處理項目,以確保清除日誌。
包含相應的請求 ID。 在對應用程式日誌中的錯誤進行疑難排解時,我們通常希望查看有關觸發錯誤的請求或發起人的詳細資訊。若兩個日誌包含相同的請求 ID,則可輕鬆地從一個日誌跳轉至另一個日誌。若設定適當,應用程式日誌記錄庫將寫出相應的請求 ID,並將請求 ID 設定為 ThreadLocal。若應用程式為多執行緒,則應考慮在執行緒開始處理新請求時,特別注意設定正確的請求 ID。
對應用程式日誌的錯誤垃圾郵件進行速率限制。通常,服務不會向應用程式日誌發出太多訊息,但若突然開始出現大量錯誤,則可能會突然開始寫出帶有堆疊跟踪的高速率超大型日誌項目。我們發現,可防止這種情況發生的一種方法是,限制給定記錄器將記錄日誌的頻率。
優先使用格式字串而非 String#format 或字串串連。較早的應用程式日誌 API 操作接受單一字串訊息,而非 log4j2 的 varargs 格式字串 api。若使用 DEBUG 陳述式檢測代碼,但將生產設定為 ERROR 層級,則可能會浪費精力來格式化略過的 DEBUG 訊息字串。某些日誌記錄 API 操作支援傳入任意物件,這些物件僅在寫出日誌項目時,才會叫用其 toString() 方法。
記錄失敗服務叫用的請求 ID。 若服務被叫用並傳回錯誤,則該服務可能會傳回請求 ID。我們發現,在日誌中包含請求 ID 非常有用,這樣,若我們需要跟進該服務擁有者,便可讓他們輕鬆地找到自己的相應服務日誌項目。逾時錯誤讓這個問題變得棘手,因為該服務可能尚未傳回請求 ID,或者用戶端庫可能尚未對其進行解析。但是,若我們從服務傳回了請求 ID,則會將其記錄下來。

高輸送量服務最佳實務

對於 Amazon 的絕大多數服務而言,記錄每個請求並不會產生不合理的費用開銷。輸送量較高的服務會進入灰色區域,但我們仍然經常記錄每個請求。例如,很自然地假設,DynamoDB 僅用於在每秒超過 2000 萬個請求的 Amazon 內部流量高峰期間,不會記錄太多,但實際上它卻記錄每個請求,以進行疑難排解,以及出於稽核和合規性原因。以下是我們在 Amazon 使用的一些高級技巧,這些技巧可讓日誌記錄更有效率,並提高每個主機的輸送量:

日誌取樣。 不是寫入每個項目,而是考慮寫出每 N 個項目。每個項目還包括略過的項目數,以便指標彙總系統可以估計其計算的指標中的真實日誌量。其他取樣演算法,如儲槽取樣,可提供更具代表性的範例。其他演算法將日誌記錄錯誤或緩慢的請求優先於成功、快速的請求。但隨著取樣的進行,協助客戶並排解特定失敗的能力卻喪失了。某些合規性要求完全不允許這樣做。
卸載序列化並將日誌排清至單獨的執行緒。 這是一個簡單且常用的變更。
頻繁的日誌輪換。 每小時輪換日誌檔案日誌似乎很方便,因此您要處理的檔案更少,但透過每分鐘輪換一次,可以改善一些情況。例如,讀取和壓縮日誌檔案的代理程式將從頁面快取、而非磁碟中讀取檔案,並且壓縮和傳送日誌的 CPU 和 IO 將分散在該小時內,而不是始終在該小時結束時觸發。
寫入預壓縮的日誌。 若日誌傳送代理程式在將日誌傳送至存檔服務之前對其進行壓縮,則系統 CPU 和磁碟將定期出現尖峰。透過將壓縮後的日誌串流至磁碟,可以分攤這筆費用,並將磁碟的 IO 減少一半。但這會帶來一些風險。我們發現,使用壓縮演算法很有用,它可以在應用程式崩潰時處理截斷的檔案。
寫入 ramdisk / tmpfs。 對於服務而言,不是將日誌寫入磁碟,而是將其寫入記憶體,直至從伺服器傳出,這樣可能會更容易。根據我們的經驗,與每小時輪換日誌相比,這對每分鐘輪換日誌更有效。
記憶體內彙總。 若必須在一部電腦上每秒處理數十萬個事務,則針對每個請求撰寫一個日誌項目可能會太昂貴。但略過此操作會在很大程度上損失可觀察性,因此我們發現,不過早最佳化會有所幫助。
監控資源使用率。 我們關注要達到某種擴展限制的距離。我們量測每個伺服器的 IO 和 CPU,以及日誌記錄代理程式消耗了多少資源。在執行負載測試時,我們將其執行足夠長的時間,以便可以證明我們的日誌傳送代理程式可以跟上我們的輸送量。

配備正確的日誌分析工具

在 Amazon,我們營運所撰寫的服務,因此我們都需要成為解決其問題的專家。這包括能夠輕鬆地進行日誌分析。從用於查看相對較少日誌的本機日誌分析,到用於篩选和匯總大量日誌結果的分散式日誌分析,我們有許多工具可供使用。

我們發現,在團隊中投資工具和 Runbook,以便進行日誌分析,這一點很重要。若日誌現在較少,但服務會隨著時間發展,則我們應關注目前的工具何時停止擴展,以便對採用分散式日誌分析的解決方案進行投資。

本機日誌分析

日誌分析過程可能需要使用各種 Linux 命令行公用程式。例如,常見的「在日誌中尋找最主要的對話者 IP 地址」只需以下工具:

cat log | grep -P "^RemoteIp=" | cut -d= -f2 | sort | uniq -c | sort -nr | head -n20

然而,還有許多其他工具可用於解答日誌中更複雜的問題,包括:

• jq: https://stedolan.github.io/jq/
• RecordStream: https://github.com/benbernard/RecordStream

分散式日誌分析

任何大數據分析服務都可以用來進行分散式日誌分析 (例如,Amazon EMR、Amazon Athena、Amazon Aurora 和 Amazon Redshift)。不過,某些服務配備了日誌記錄系統,例如 Amazon CloudWatch Logs。

CloudWatch Logs Insights
• AWS X-Ray:https://aws.amazon.com/xray/
• Amazon Athena:https://aws.amazon.com/athena/

結論

作為服務擁有者和軟體開發人員,我花費了大量時間來查看檢測輸出 (儀表板上的圖形、個別日誌檔案),以及使用分散式日誌分析工具 (如 CloudWatch Logs Insights)。這些是我最喜歡做的事情。在完成一些艱鉅的任務後需要休息時,我可以給電池充電,並深入查看某些日誌來獎勵自己。我會先問一些「為什麼這個指標會在這裡飆升?」或者「這項操作的延遲會更低嗎?」之類的問題。 當我的問題陷入僵局時,我經常會找出一些對代碼有幫助的量測值,所以我新增了檢測、測試,並將代碼審查傳送給我的隊友。

雖然我們使用的託管服務附帶許多指標,但我們仍需要花費大量的心思來檢測我們自己的服務,以便具備讓其有效運作所需的可視性。在運作事件發生期間,我們需要快速確定出現問題的原因,以及如何解決該問題。在儀表板上使用正確的指標至關重要,這可讓我們快速進行問題診斷。另外,由於我們一直在變更服務,新增功能,以及變更它們與相依項的互動方式,因此,更新和新增正確檢測的工作永無止境。

• 「查看資料」,前 Amazon 員工 John Rauser︰https://www.youtube.com/watch?v=coNDCIMH8bk (包括在 13:22 時,他將逐字列印出日誌以便更好地查看)
• 「調查異常」,前 Amazon 員工 John Rauser︰https://www.youtube.com/watch?v=-3dw09N5_Aw
• 「人們如何看待資料」,前 Amazon 員工 John Rauser︰https://www.youtube.com/watch?v=fSgEeI2Xpdc
https://www.akamai.com/uk/en/about/news/press/2017-press/akamai-releases-spring-2017-state-of-online-retail-performance-report.jsp


作者簡介

David Yanacek 是 AWS Lambda 的資深首席工程師。自 2006 年以來,David 一直擔任 Amazon 的軟體開發人員,之前負責 Amazon DynamoDB 和 AWS IoT、內部 Web 服務框架,以及車隊營運自動化系統的開發。David 工作中最喜歡的活動之一是,執行日誌分析並篩選操作指標,以尋找讓系統隨時間推移而執行越來越平穩的方法。

使用負載卸除以免過載 避免無法克服的佇列待辦事項