天天看點

鍊路追蹤_鍊路追蹤介紹

最近為我們的遊戲伺服器接傳入連結路追蹤系統,了解了公司内、公司外的多個鍊路追蹤元件,鍊路追蹤系統可以用于監控分布式系統的性能、調用關系、定位問題等。

鍊路追蹤中有個很重要的概念叫做

OpenTracing

,它不是一個可以下載下傳、可以引入的元件或者程式,而是一種标準,在java裡可以了解為定義了一系列鍊路追蹤的

interface

,各個開發基礎元件的公司可以基于這些接口,開發自己的鍊路追蹤系統。而業務開發者,隻需要通過

opentracing

的api來進行業務埋點,具體實作可以随意選擇,切換成本非常低,隻需要修改數行代碼就可以從一個鍊路追蹤元件切換到另一個鍊路追蹤元件;前提就是這些元件是符合

Opentracing

規範。

後面我将介紹下我們的遊戲伺服器引傳入連結路追蹤系統是解決了什麼問題,針對具體的問題,我也會從兩方面介紹:

  1. 如果沒有

    Opentracing

    ,我如何去實作,實作方式存在哪些問題
  2. Opentracing

    如何解決上面提到的問題

通過兩者的對比,更好的了解

Opentracing

的設計。

鍊路追蹤有什麼用

函數調用監控

随着每個疊代需求的增加,我們的遊戲伺服器業務代碼越來越多,玩家登入需要處理的玩法系統也越來越多,導緻登入慢,如何去定位哪一部分耗時最多,進而去優化呢?

假設我們的登入邏輯如下

  • 最土的辦法,加日志
  • 稍微優美點的方法,将監控的邏輯構造出一個對象,讓監控代碼收斂,簡潔一些

最終得到的結果就是日志檔案,結果如下:

這個日志結果存在幾個問題:

第一個問題:如果隻有三個子產品,日志不長,其實看着也還行吧,但是我們伺服器現狀是,一條日志可以有20行左右,全是這樣的

xxx cost yyy ms

,非常的不直覺。

第二個問題:統計顆粒度不夠細,比如得出了

god animal

子產品很慢,但是

initGodAnimal

裡可能也包含了很多的邏輯,包含好幾次的db、redis查詢,我們的追蹤日志需要繼續的細化。

第三個問題:文本可視化程度不夠,方法間調用關系不明确,日志裡都屬于同一層,展現不出調用關系

如何細化?

  • 日志的方式如何細化

initBuilding

initGodAnimal

函數中像之前一樣繼續加日志

  • 構造出監控對象的如何繼續細化?

上面的這種做法可以解決問題,但是很不優雅,需要修改幾乎所有方法的簽名。

  • Opentracing用法

這裡的

Tracer

Span

Scope

等都是

Opentracing

定義的接口

GlobalTracer是一個工具類(也可以自己實作個類似的,這個應該不屬于opentracing規範内的東西),可以通過get方法擷取一個單例的

Tracer

對象,前面提到的不同基礎元件開發公司,主要開發的就是Tracer的具體實作,我們隻需要在程式啟動時,将第三方實作好的Tracer對象注入到

GlobalTracer

中,是以在不同的第三方鍊路追蹤系統之間切換時,隻需要修改一下注入對象;而業務代碼的埋點邏輯,我們都是基于

interface

程式設計,是以無需修改。即使我們在啟動伺服器時,沒有向

GlobalTracer

中注入任何對象,它内部也預設實作了一個沒有任何邏輯的

NoopTracer

,我們的代碼執行也不會有任何異常。通過這種單例模式,可以不需要将 tracer對象作為參數傳入每一個需要監控的方法。

一個Span對象就是一條監控記錄,與前面自己實作的Monitor不同的地方是,新的代碼中構造了很多個Span對象,但是之前的Monitor對象隻有一個。Span隻關注自己需要監控的代碼,比如login方法中的Span,統計的是登入的耗時,比如initBuilding中的span統計的是初始化建築的耗時。

span的大概結構如下:

spanId是每個Span節點唯一的,很好生成,不介紹了。但是

traceId

,

parentId

這些與上下文相關聯的資訊如何寫入呢?

一條鍊路,總歸會有一個起始節點,對登入來說,就是我們的login方法入口。初始節點就是一個建立traceId的合适地方,因為代表了一條鍊路的開始。

如何判斷是不是鍊路的起點呢?上面的代碼中,其實我們建立span的方法都是一模一樣的。差別在于login方法中多了

Scope scope = tracer.scopeManager().activate(span)

這樣的一行代碼,而其他init方法中沒有。

ScopeManager

是上下文管理器,也是一個接口,可以有不同的實作。以大多數java伺服器應用的并發模型來說,都是采用多線程的方式。即玩家登入的處理邏輯是靠一個線程池來處理的,一個線程在一段時間内,處理的是同一個玩家的登入請求,登入的整條鍊路都是在一個線程内處理的(rpc,mysql等遠端調用,對本機來說還是一個線程)。則可以把鍊路的上下文資訊放入線程中,即

ThreadLocal

針對于

ThreadLocalScopeManager

,activate(span)方法就是将目前這個span對象存到線程本地變量中,當下一個Span對象構造時,就判斷下目前本地變量裡是否已經存在span對象(其實是一個連結清單結構,因為可以有多層調用),如果存在,則認為線程本地變量中的span對象是自己的父節點,則可以把自己相應的

traceId

,

parentId

字段補充完整。并且因為threadLocal的存在,span對象也不需要像上面自己實作的monitor對象一樣作為參數傳入每一個方法。

ScopeManager

一般會實作autoClose接口,是以用try文法糖來實作自動關閉,進而将本地變量中的Span對象删除。

通過

ScopeManager

對象,就可以展現出不同span之間的調用關系,當我們需要對目前監控的方法的子方法進行調用時,就可以通過

ScopeManager

來展現出這種調用的父子關系。

鍊路追蹤_鍊路追蹤介紹

span

在時序圖上,就可以展示出如上圖這樣的效果,整個login耗時假設100ms,前30ms用來initBuilding,接下裡的20ms用于initArmy…不僅每個階段的耗時可以統計出來,也能把他們的時序順序,調用關系充分的展現出來。

遠端調用監控

上面都在将本地的調用監控,現在的系統大多數是分布式系統,存在各種遠端調用,mysql,redis等,這些也是我們需要監控的地方。

拿上面的登入流程舉例,我們得知登入流程慢,其實可以以90%以上的信心認為是db查詢耗時太慢導緻登入耗時久,因為正常的記憶體操作都是非常快的,不會有太大問題。上面的那種埋點方式,重複代碼多,作用其實也不大。因為沒有埋在關鍵點位:rpc調用,mysql,redis這些耗時的操作上。

mysql,redis埋點

db查詢由于io和網絡延遲的存在,是耗時最嚴重的地方,也是監控需要重點覆寫的地方。隻需要找到這些調用最底層的地方,進行統一埋點構造span對象,就可以監控所有的db操作。前面提到Span對象可以設定tag,在這裡可以把db語句等放置進去

rpc埋點

mysql,redis也可以認為是遠端調用,但是與一般rpc相比還是存在一些差異。當我們通路mysql和redis時,可以認為mysql,redis伺服器就是終點了,它們除了處理我們的請求,不會主動的發起其他的請求或者子調用。

但是rpc伺服器就不一樣了,比如A伺服器調用了B伺服器的一個接口,B伺服器的處理邏輯也是一條複雜的鍊路,由多個子調用組成。前面是通過

ScopeManager

來控制一個程序内不同span之間的調用關系,但是AB伺服器不是同一個程序,

ScopeManager

顯然做不到這件事。那麼在B伺服器中建立的span對象,他的

traceId

,

parentId

該如何指派呢?

B伺服器的

traceId

,

parentId

應該繼承自A伺服器,是以需要一個機制,來将A伺服器的

traceId

,

parentId

來傳送給B伺服器。

Tracer

定義了兩個接口來實作不同程序間傳遞上下文的需求:Tracer.Inject(…) 和 Tracer.Extract(…)。

inject方法可以将上下文資訊以指定的方式序列化,rpc client隻需要将序列化得到的對象當作rpc調用中的一個參數傳出去,rpc server端讀取這個參數,将其反序列化得到

SpanContext

對象,然後rpc server在建立自己的span對象時,基本步驟與之前完全一樣,隻需要在建立第一個span對象時将得到的spanContext對象設定為自己的父節點(即為自己建立的span對象的

traceId

,

parentId

進行指派)。

最終A,B伺服器建立的span對象都會發送到統一的後端伺服器。這個伺服器則根據traceid,spanid,parentid來将這些單獨的span對象互相關聯起來,形成調用鍊。

鍊路可視化界面

前面提到了,日志形式的監控,可視化非常差,不能讓人直覺的看出哪個環節慢了,不同子產品的調用、時序關系等,但是開源的鍊路追蹤系統,他們的背景可視化界面都非常的清晰。我們的伺服器最終選用了uber開源的jaeger來做鍊路追蹤。

以login方法為root span節點(root節點用來将後續所有的子調用關聯起來),mysql,redis,rpc最底層通用接口進行埋點,所有init方法無需建立新的span(基于我們對耗時都處于mysql,redis,rpc的判斷)

登入效果如下:

鍊路追蹤_鍊路追蹤介紹

span

可以看出登入總共耗時732ms,mysql和redis總共執行次數為115次,每一次的查詢語句,耗時、時序關系在上面都顯示的清清楚楚。

有了這個可視化界面可以幫助我們發現很多問題:

  1. 某些sql語句耗時明顯過大,想辦法優化
  2. 有幾條sql在一次登入中居然出現了十幾次,需要優化處理邏輯

參考連結

  • opentracing官網
  • opentracing中文文檔
  • opentracing java api

繼續閱讀