01
背景
愛奇藝海外後端研發組支撐了愛奇藝海外PHONE/PCW/TV三端後端的相關業務。除了負責三端的後端服務外，還包含了海外積分業務，彈窗，各類節目的預約系統等。除此以外，還有落地了一些列基礎設施，比如快速支援産品的各類營運配置和實驗訴求的IQ背景；助力産品營運實作精細化營運的政策引擎；實作流量回放和壓測的品質保障平台等。
繁多業務的穩定運作依賴完善的日志體系，是以業務代碼常常會列印許多日志協助監控和排查業務代碼運作中的問題。但日志的列印卻對項目運作性能有一定的影響。我們翻閱了大量資料，可以找到很多不同架構的日志性能對比介紹，但缺少工程實踐所需要的提煉性的日志列印SOP。再者，分布式系統是目前的主流，在日志列印過程中，節點間都是各自無狀态的、獨立的列印同一個請求的資訊，這會導緻了很大的資訊備援和資源浪費，對服務性能也不友好。
如上圖，服務1調用了服務3，後在串行調用服務2，服務2内部依賴服務3。以上情況，服務1會記錄請求服務3的詳情資訊，服務2會記錄請求服務3的詳情資訊，服務3會記錄所有請求的資訊。于是一次鍊路包含了4次同樣的日志。
為了解決以上問題，我們進行了分布式系統日志列印優化方案的專題建設，主要包含兩部分内容：
（1）擷取打日志對于項目性能的實際損耗的量化資料，提煉性的日志列印SOP，助力項目性能提升并為以後的日志列印提供參考。
（2）思考日志列印的鍊路全局性，實作分布式服務節點間有狀态的日志記錄。
通過以上兩部分内容的建設，減少分布式鍊路下的日志列印的資源和性能消耗。提高系統性能，減少系統損耗。
本文主要分享我們在分布式系統日志列印優化方案的探索思考與實踐過程。
02
單系統優化日志列印探索與實踐
目前最為流行的架構有log4j，log4j2以及logback。一般認為，log4j2是對log4j的更新，是以我們将對最主流log4j2和logback 1.3.0 架構進行實驗對比，擷取性能資料，并總結最佳實踐，為我們業務系統列印日志提供流程性規範。
2.1 多項次元對比，擷取日志列印最佳實踐方案
我們選擇了容器部署，資源：2c4g，獨立部署項目。項目内包含一個API，API功能是根據入參控制輸出不同大小的日志。
2.1.1 對log4j2的列印性能進行量化研究
log4j2異步
日志大小：2KB，異步
log4j2同步
log4j2壓測結論
通過以上的資料很容易生成以下圖表。
從上圖可知：
- 在小并發數量的時候，log4j2的性能是一緻的，在并發數量增大到一定數量時，異步列印的性能明顯優于同步列印。
- log4j2異步列印同樣存在性能瓶頸。
- log4j2的同步列印的性能瓶頸在于IO瓶頸，每秒的IO大小在 2635 ✖️ 2kb = 5.15MB左右。
2.1.2 對logback的列印性能進行量化研究
logback 異步
logback同步列印
logback壓測結論
通過logback的壓測資料很容易生成以下圖表。
從上圖可知：
- 在小并發數量的時候，log4j2的性能是一緻的，在并發數量增大到一定數量時，異步列印的性能明顯優于同步列印。
- logback異步列印同樣存在性能瓶頸
- log4j2的同步列印的性能瓶頸在于IO瓶頸，每秒的IO大小在 2650 ✖️ 2kb = 5.2MB左右，IO的大小與log4j2大體相同。
2.1.3 logback和log4j2的對比
同步對比
通過以上表格資料可以擷取下面的對比圖
異步對比
通過以上表格資料可以擷取下面的對比圖
從以上的可知：
- 無論同步還是異步。在并發度超過一定門檻值後，logback的性能優于log4j2。
- 并發在一定範圍内，logback的性能與log4j2的性能相當。
2.1.4 針對logback在不同場景的性能進行量化比較
從2.1.3節結論可知，無論同步還是異步。在并發度小于門檻值前，logback和log4j2性能相當，在并發度超過一定門檻值後，logback的性能優于log4j2。是以，以下我們将對logback在不同場景下的性能進行詳細探索。
logback同步列印不同大小日志在相同并發數下接口性能資料
并發數 = 100，同步
logback異步列印不同大小日志在相同并發數下接口性能資料
并發數 = 100，異步
通過以上的資料，可以繪得以下關系圖
從上圖可以得到：
- 日志大小在一定區間内，對于性能無影響，超過一定限制，性能下降明顯。
- 從同步列印日志的資料可知，并發數一定時，IO的數量存在瓶頸，即機關時間内IO的大小不随每次IO的增大而等比例增大。實驗資料的瓶頸在160MB左右。
- logback異步列印對于日志大小的敏感度很小，因為在異步列印的隊列滿後，可以采取抛棄業務日志的政策。
2.2 最佳實踐總結
- 優先使用logback作為日志輸出的架構，減少日志列印對項目性能影響
- 在高并發情況并且業務日志為非必須的情況下，使用logback異步列印
- 判斷業務日志是強依賴，logback異步列印日志需要格外注意配置nerverBlock = true。此時需要若項目的單次請求的列印日志size小于2KB，則項目每秒IO資料不宜大于5MB。
2.3工程項目優化
根據以上最佳實踐，我們選擇一個愛奇藝海外後端研發組的項目進行試點改造，分析性能變化。
2.3.1 項目介紹
愛奇藝海外後端研發組負責PHONE/PCW/TV三端的對應的海外愛奇藝後端業務，主要包含了頁面業務資料的穩定輸出的TOC服務，靈活高效可擴充的IQ營運背景，用于精細化營運的政策引擎，以及同步節目資料的資料中心服務等。
我們選擇一個TOC的非card結構的服務作為試點，原因是該項目包含很多API，日志列印的場景較多。該項目部署在新加坡，4C8G容器化部署，峰值單機QPS在120左右。
2.3.2 性能優化結果
異步化改造後，P99由 78.8ms下降到74ms，P999由180ms下降到164.5ms。
不同項目的情況不同，如果是單機流量大或者列印日志較多的項目，異步改造相信會有更大的性能提高。
2.4 總結
單機日志的性能優化主要工作在于擷取不同日志架構的性能以及擷取相同日志架構在不同場景下的性能。希望這部分資料可以給遇到相同困境的同行帶來幫助。除此以外，我們還規範化了日志的列印方式，通過對業務SLA分級，在日志層面說明此處的日志是什麼原因，如果是異常是什麼級别的異常，友善各業務同學能及時了解到不同報警的緊急程度，利于作出優先級的判斷和流程化的應對措施。
03
分布式變量共享在日志列印中的應用
以上章節介紹了單機系統的日志列印優化，但是目前的系統基本都是分布式系統，那麼在分布式系統下，日志列印有什麼痛點和解決方案？我們思考了分布式系統下日志鍊路列印的優化方案，下面是在分布式系統下日志列印優化的思考和實踐。
3.1簡介
會看網際網路技術的演進過程，從單體系統演進到分布式系統是一個非常重要的特征。但不可否認，事物變化在總體上更具有優勢，但在分支上總會遇到新的挑戰。單體系統同樣也有分布式系統所沒有的優勢，比如本地事務，共享代碼以及共享變量。從列印日志的角度看，單體系統對于同一個服務的調用可以進行下沉。因為日志的記錄是在同一個項目内，是可檢視的，甚至是可約定的。而在分布式系統中，通常會進行功能子產品進行劃分，隸屬于不同的開發團隊，是以不同服務節點的日志列印通常是無法通信，基于這種原因，基本所有的開發團隊都會應打盡打，整個鍊路的日志就會很備援，導緻了資源浪費和分布式系統的性能下降。
3.2 全鍊路追蹤系統介紹
在分布式系統，一次外部請求往往需要内部多個子產品，多個中間件，多台機器的互相調用才能完成。在這一系列的調用中，可能有些是串行的，而有些是并行的。在這種情況下，我們如何才能确定這整個請求調用了哪些應用？哪些子產品？哪些節點？以及它們的先後順序和各部分的性能如何呢？鍊路追蹤的目的就是要解決上面所提出的問題，也就是将一次分布式請求還原成調用鍊路，将一次分布式請求的調用情況集中展示，比如，各個服務節點上的耗時、請求具體到達哪台機器上、每個服務節點的請求狀态等等。比如全鍊路系統之一的zipkin，其架構圖如下：
全鍊路追蹤系統支援鍊路日志的采樣和變量透傳，我們參考了全鍊路的設計思路來優化我們的分布式系統。
3.3 共享變量對于日志采樣的使用
3.3.1 背景介紹
該問題集中展現在我們的政策引擎系統中，政策引擎系統是為實作精細化營運而設計落地的系統，主要是可以實作不同人群畫像的認定識别，據此投放不同的政策。随着系統的落地，接入的業務增長迅速。目前已有愛奇藝海外頁面資料的CARD業務，彈窗業務，廣告業務，互動營銷業務，推薦業務，導航以及旅程業務等已經接入。但是以上不同的系統又存在一定的依賴關系互相調用。
而因為業務需要，政策引擎的請求依賴post請求，網關日志無法解析post的請求參數，是以我們需要業務記錄每次請求詳情。另外，政策引擎強依賴使用者畫像資料，畫像資料分别存在BI和臉譜兩個服務中，在以往經驗中，政策命中失敗的原因中，90%左右時是以使用者畫像資料沒有及時更新資料，為了便于排查定位問題，政策引擎會記錄每次使用者請求的使用者畫像資料。而政策引擎的QPS很高，是以單日的日志體量就有150G左右。如何優雅地優化這部分日志是我們遇到的痛點。
政策引擎的流量主要包含了彈窗，廣告，頂導航以及iq，推薦，互動營銷。
但是，我們發現，有一部分流量有明顯的鍊路特性。當用戶端請求确定了頂導航後，就會擷取關聯的page。
- 關聯page可能存在一組資料，此時需要請求政策引擎，擷取符合使用者畫像的頁面。
- 頁面内部關聯了多組card，此時需要請求政策引擎，擷取符合使用者畫像的card。
- card實際關聯不同業務資料，其中包含互動營銷服務，推薦服務。而互動營銷和推薦又會請求政策引擎，來擷取符合人群畫像的資料。
可以從分析得出，一次使用者請求，包含的微服務分别請求了政策引擎。而在request的一個生命周期内，使用者的request資料是确定一樣的，使用者畫像資料是确定一樣的。
3.3.2 解決方案
如上分析，很容易想到的是統一給交給政策引擎統一記錄。政策引擎在TraceContext上添加辨別符，表示該請求生命周期内，是否有過記錄，有則不記錄，無則記錄。
如上圖所示，服務1請求政策引擎後，在TraecContext内增加辨別符，表示該請求Trace已經記錄過日志。在後續節點即服務2，服務3再次請求政策引擎時，則無需再重複記錄。這樣做可以減少很多的日志記錄。
但是，這樣有會存在以下問題：如果存在5xx錯誤，政策引擎服務失敗導緻了沒有記錄到相應請求，請求記錄存在丢失情況，這樣會給問題排查代理巨大的困難。
經過對比分析，最終确定通過分布式系統下共享變量可以很好的解決以上兩個問題。
以上請求1，2，4，5，7，8全部需要判斷traceContext上下文的logBusiness字段，如果存在則無需在記錄，不存在則記錄日志并且把logBusiness設定為true。
比如，這是一次全部200的請求，那麼1請求後到達政策引擎判斷traceContext上下文的logBusiness字段為false，那麼就會記錄下該次請求并且将logBusiness設定為true，在後續的4，5，7，8中，則無需再次記錄日志。即便4，5，7，8出現異常，通過traceId和1中記錄的請求，仍然可以還原請求政策引擎的現場，
再比如1請求失敗，如果是499逾時請求，因為逾時對服務端透明，政策引擎繼續執行，那麼政策引擎列印日志，并且設定traceContext上下文的logBusiness字段為true。但是對于服務1，因為逾時緣故，則會備援記錄一份資料。在4請求中，由于traceContext上下文的logBusiness仍然為false，是以會重新記錄，并且設定logBusiness為true，在後續的7中則不會記錄。
在比如如果1請求失敗，且是5xx請求，那麼，1會記錄，4中會再次記錄。
是以此種方式可以在保證還原日志鍊路完整的前提下，實作鍊路日志的最小化。
3.3.3 總結
我們對政策引擎服務進行了優化，日志約可從之前的150G/天下降到30G/天。flink任務搜集和處理日志的隊列資源消耗也相應的降低了。
04
總結展望
本文主要從單體的日志優化和分布式系統日志優化兩方面介紹了分布式系統日志列印優化方案的探索與實踐過程。對目前主流的日志架構進行性能對比，擷取資料，形成最佳實踐，給我們的業務項目的日志列印方式提供标準接入方案，介紹了我們團隊項目通過改進日志列印方式得到的收益。對特定場景下，分布式系統列印日志無狀态的問題給出了創新型的解決方案，解決了不同或者相同的分布式節點重複記錄日志的問題。這裡多提一句，經過我們的系列思考，分布式共享變量擁有廣闊的應用前景，除本文介紹的有狀态的優化日志列印之外，對于資料不一緻零容忍或者弱容忍的場景，可以用該方法很好的降低瓶頸服務的流量壓力，提高鍊路性能，當然，這需要配合資料壓縮和解壓縮算法。在未來實踐中，我們有機會再和同行分享我們的思考和實踐過程。
作者:海外技術産品團隊
來源:微信公衆号:愛奇藝技術産品團隊
出處:https://mp.weixin.qq.com/s/DfQ8J75AFHArqzyzEjMG7Q