分布式鏈路追蹤(Tracing)系統(tǒng) - Jaeger在Golang中的使用

先從微服務(wù)說起

微服務(wù)

一個(gè)完整的微服務(wù)體系至少需要包括:

  • CI / CD 也就是自動化部署
  • 服務(wù)發(fā)現(xiàn)
  • 統(tǒng)一的PRC協(xié)議
  • 監(jiān)控
  • 追蹤(Tracing)

要配置上面這些東西可謂說超級復(fù)雜, 所以我建議讀者 如果可以直接使用istio

istio

它強(qiáng)大到包含了微服務(wù)開發(fā)需要考慮的所有東西, 上圖中的"Observe"就包括了這篇文章所說的"鏈路追蹤(Tracing)".

但軟件行業(yè)沒有銀彈, 強(qiáng)大的工具自然需要強(qiáng)大的人員去管理, 在進(jìn)階為大佬之前, 還是得研究一些傳統(tǒng)的方案以便成長, 所以便有了這篇文章.

Tracing在微服務(wù)中的作用

和傳統(tǒng)單體服務(wù)不同, 微服務(wù)通常部署在一個(gè)分布式的系統(tǒng)中, 并且一個(gè)請求可能會經(jīng)過好幾個(gè)微服務(wù)的處理, 這樣的環(huán)境下錯(cuò)誤和性能問題就會更容易發(fā)生, 所以觀察(Observe)尤為重要,
這就是Tracing的用武之地, 它收集調(diào)用過程中的信息并可視化, 讓你知道在每一個(gè)服務(wù)調(diào)用過程的耗時(shí)等情況, 以便及早發(fā)現(xiàn)問題.

Jaeger UI

在上圖可以看到api層一共花了4.03s, 然后其中調(diào)用其他服務(wù): 'service-1'花了2.12s, 而service-1又調(diào)用了'service-2'花費(fèi)了2.12s, 用這樣的圖示很容易就能排查到系統(tǒng)存在的問題. 在這里我只展示了時(shí)間, 如果需要追蹤其他信息(如錯(cuò)誤信息)也是可以實(shí)現(xiàn)的.

為什么是Jaeger

筆者正在學(xué)習(xí)Golang, 選用使用Golang并開源的Tracing系統(tǒng) - Jaeger當(dāng)然就不再需要理由了

Uber出品也不會太差丈牢。

安裝

官方文檔在此

為了快速上手, 官方提供了"All in One"的docker鏡像, 啟動Jaeger服務(wù)只需要一行代碼:

$ docker run -d --name jaeger \
  -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 \
  -p 5775:5775/udp \
  -p 6831:6831/udp \
  -p 6832:6832/udp \
  -p 5778:5778 \
  -p 16686:16686 \
  -p 14268:14268 \
  -p 9411:9411 \
  jaegertracing/all-in-one:1.12

具體端口作用就不再贅述, 官方文檔都有.

All in One只應(yīng)該用于實(shí)驗(yàn)環(huán)境. 如果是生產(chǎn)環(huán)境, 你需要按官方[這樣部署].(https://www.jaegertracing.io/docs/1.12/deployment/)
本文在后面會講到部署并使用Elasticsearch作為存儲后端.

現(xiàn)在用于測試的服務(wù)端就完成了, 你可以訪問http://{host}:16686來訪問JaegerUI, 它像這樣:

JeagerUi

客戶端

部署完服務(wù)器就可以編寫客戶端了, 官方提供了Go/Java/Node.js/Python/C++/C#語言的客戶端庫, 讀者可自行選擇, 使用方式可在各自的倉庫中查看.

我也只實(shí)驗(yàn)了Golang客戶端, 先從最簡單的場景入手:

在單體應(yīng)用中實(shí)現(xiàn)Tracing.

在編寫代碼之前還得理解下Jaeger中最基礎(chǔ)的幾個(gè)概念, 也是OpenTracing
的數(shù)據(jù)模型: Trace / Span

  • Trace: 調(diào)用鏈, 其中包含了多個(gè)Span.
  • Span: 跨度, 計(jì)量的最小單位, 每個(gè)跨度都有開始時(shí)間與截止時(shí)間. Span和Span之間可以存在References(關(guān)系): ChildOf 與 FollowsFrom

如下圖 (來至開放分布式追蹤（OpenTracing）入門與 Jaeger 實(shí)現(xiàn))

單個(gè) Trace 中囤官，span 間的因果關(guān)系


        [Span A]  ←←←(the root span)
            |
     +------+------+
     |             |
 [Span B]      [Span C] ←←←(Span C 是 Span A 的孩子節(jié)點(diǎn), ChildOf)
     |             |
 [Span D]      +---+-------+
               |           |
           [Span E]    [Span F] >>> [Span G] >>> [Span H]
                                       ↑
                                       ↑
                                       ↑
                         (Span G 在 Span F 后被調(diào)用, FollowsFrom)

接下來是代碼時(shí)間, 參考項(xiàng)目的Readme和搜索引擎不難寫出以下代碼

package tests

import (
    "context"
    "github.com/opentracing/opentracing-go"
    "github.com/uber/jaeger-client-go"
    "log"
    "testing"
    "time"

    jaegercfg "github.com/uber/jaeger-client-go/config"
)

func TestJaeger(t *testing.T) {
    cfg := jaegercfg.Configuration{
        Sampler: &jaegercfg.SamplerConfig{
            Type:  jaeger.SamplerTypeConst,
            Param: 1,
        },
        Reporter: &jaegercfg.ReporterConfig{
            LogSpans:           true,
            LocalAgentHostPort: "{host}:6831", // 替換host
        },
    }

    closer, err := cfg.InitGlobalTracer(
        "serviceName",
    )
    if err != nil {
        log.Printf("Could not initialize jaeger tracer: %s", err.Error())
        return
    }

    var ctx = context.TODO()
    span1, ctx := opentracing.StartSpanFromContext(ctx, "span_1")
    time.Sleep(time.Second / 2)

    span11, _ := opentracing.StartSpanFromContext(ctx, "span_1-1")
    time.Sleep(time.Second / 2)
    span11.Finish()

    span1.Finish()

    defer closer.Close()
}

代碼唯一需要注意的地方是closer, 這個(gè)closer在程序結(jié)束時(shí)一定記得關(guān)閉, 因?yàn)樵诳蛻舳酥衧pan信息的發(fā)送不是同步發(fā)送的, 而是有一個(gè)暫存區(qū), 調(diào)用closer.Close()就會讓暫存區(qū)的span發(fā)送到agent.

運(yùn)行之, 我們就可以在UI看到:


點(diǎn)擊進(jìn)入詳情就能看到我們剛剛收集到的調(diào)用信息


通過Grpc中間件使用

在單體程序中, 父子Span通過context關(guān)聯(lián), 而context是在內(nèi)存中的, 顯而易見這樣的方法在垮應(yīng)用的場景下是行不通的.

垮應(yīng)用通訊使用的方式通常是"序列化", 在jaeger-client-go庫中也是通過類似的操作去傳遞信息, 它們叫:Tracer.Inject() 與 Tracer.Extract().

其中inject方法支持將span系列化成幾種格式:

  • Binary: 二進(jìn)制
  • TextMap: key=>value
  • HTTPHeaders: Http頭, 其實(shí)也是key=>value

正好grpc支持傳遞metadata也是string的key=>value形式, 所以我們就能通過metadata實(shí)現(xiàn)在不同應(yīng)用間傳遞Span了.

這段代碼在github上有人實(shí)現(xiàn)了: https://github.com/grpc-ecosystem/go-grpc-middleware

題外話:上面的庫使用到了grpc的Interceptor, 但grpc不支持多個(gè)Interceptor, 所以當(dāng)你又使用到了其他中間件(如grpc_retry)的話就能導(dǎo)致沖突. 同樣也可以使用這個(gè)庫grpc_middleware.ChainUnaryClient解決這個(gè)問題.

在grpc服務(wù)端的中間件代碼如下(已省略錯(cuò)誤處理)

import (
    "context"
    "github.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing"
    "google.golang.org/grpc"
)

jcfg := jaegercfg.Configuration{
        Sampler: &jaegercfg.SamplerConfig{
            Type:  "const",
            Param: 1,
        },
        ServiceName: "serviceName",
    }

report := jaegercfg.ReporterConfig{
        LogSpans:           true,
        LocalAgentHostPort: "locahost:6831",
    }

reporter, _ := report.NewReporter(serviceName, jaeger.NewNullMetrics(), jaeger.NullLogger)
tracer, closer, _ = jcfg.NewTracer(
        jaegercfg.Reporter(reporter),
)

server := grpc.NewServer(grpc.UnaryInterceptor(grpc_opentracing.UnaryServerInterceptor(grpc_opentracing.WithTracer(tracer))))

在grpc客戶端的中間件代碼如下

conn, err := grpc.Dial(addr, grpc.WithUnaryInterceptor(grpc_opentracing.UnaryClientInterceptor(
    grpc_opentracing.WithTracer(tracer),
)))

現(xiàn)在服務(wù)端和客戶端之間的調(diào)用情況就能被jaeger收集到了.

在業(yè)務(wù)代碼中使用

有時(shí)候只監(jiān)控一個(gè)"api"是不夠的，還需要監(jiān)控到程序中的代碼片段(如方法)，可以這樣封裝一個(gè)方法


package tracer

type SpanOption func(span opentracing.Span)

func SpanWithError(err error) SpanOption {
    return func(span opentracing.Span) {
        if err != nil {
            ext.Error.Set(span, true)
            span.LogFields(tlog.String("event", "error"), tlog.String("msg", err.Error()))
        }
    }
}

// example:
// SpanWithLog(
//    "event", "soft error",
//    "type", "cache timeout",
//    "waited.millis", 1500)
func SpanWithLog(arg ...interface{}) SpanOption {
    return func(span opentracing.Span) {
        span.LogKV(arg...)
    }
}

func Start(tracer opentracing.Tracer, spanName string, ctx context.Context) (newCtx context.Context, finish func(...SpanOption)) {
    if ctx == nil {
        ctx = context.TODO()
    }
    span, newCtx := opentracing.StartSpanFromContextWithTracer(ctx, tracer, spanName,
        opentracing.Tag{Key: string(ext.Component), Value: "func"},
    )

    finish = func(ops ...SpanOption) {
        for _, o := range ops {
            o(span)
        }
        span.Finish()
    }

    return
}

使用

newCtx, finish := tracer.Start("DoSomeThing", ctx)
err := DoSomeThing(newCtx)
finish(tracer.SpanWithError(err))
if err != nil{
  ...
}

最后能得到一個(gè)像這樣的結(jié)果


可以看到在服務(wù)的調(diào)用過程中各個(gè)span的時(shí)間，這個(gè)span可以是一個(gè)微服務(wù)之間的調(diào)用也可以是某個(gè)方法的調(diào)用。

點(diǎn)開某個(gè)span也能看到額外的log信息。

通過Gin中間件中使用

在我的項(xiàng)目中使用http服務(wù)作為網(wǎng)關(guān)提供給前端使用，那么這個(gè)http服務(wù)層就是root span而不用關(guān)心父span了奋刽，編寫代碼就要簡單一些。

封裝一個(gè)gin中間件就能實(shí)現(xiàn)

import (
    "context"
    "github.com/gin-gonic/gin"
    "github.com/opentracing/opentracing-go"
    "github.com/opentracing/opentracing-go/ext"
)

jcfg := jaegercfg.Configuration{
        Sampler: &jaegercfg.SamplerConfig{
            Type:  "const",
            Param: 1,
        },
        ServiceName: "serviceName",
    }

report := jaegercfg.ReporterConfig{
        LogSpans:           true,
        LocalAgentHostPort: "locahost:6831",
    }

reporter, _ := report.NewReporter(serviceName, jaeger.NewNullMetrics(), jaeger.NullLogger)
tracer, closer, _ = jcfg.NewTracer(
        jaegercfg.Reporter(reporter),
)

engine.Use(func(ctx *gin.Context) {
        path := ctx.Request.URL.Path

        span := tracer.StartSpan(path,
            ext.SpanKindRPCServer)
        ext.HTTPUrl.Set(span, path)
        ext.HTTPMethod.Set(span, ctx.Request.Method)
        c := opentracing.ContextWithSpan(context.Background(), span)

        ctx.Set("ctx", c)

        ctx.Next()

        ext.HTTPStatusCode.Set(span, uint16(ctx.Writer.Status()))
        span.Finish()
    })

如果需要向下層傳遞context則這樣獲取context

func Api(gtx *gin.Context) {
  ctx = gtx.Get("ctx").(context.Context)
}

結(jié)語

使用trace會入侵部分代碼艰赞，特別是追蹤一個(gè)方法佣谐，但這是不可避免的。

甚至需要每個(gè)方法都需要添加上ctx, 關(guān)于這點(diǎn)有興趣的朋友可以讀一下這篇文章: Golang Context 是好的設(shè)計(jì)嗎方妖？
(原文找不到了, 將就看一下)

但其實(shí)并不是整個(gè)系統(tǒng)的服務(wù)都需要追蹤狭魂，可只針對于重要或者有性能問題的地方進(jìn)行追蹤。

部署篇

使用Elasticsearch作為存儲后端

在一篇文章 開放分布式追蹤（OpenTracing）入門與 Jaeger 實(shí)現(xiàn)中偶然發(fā)現(xiàn)阿里云支持為Jaeger提供存儲后端, 但怕于阿里云拖更, 所以也就沒使用阿里云產(chǎn)品.

筆者對于Elasticsearch更為熟悉, 故選擇它了.

es的部署就不說了.

這里是jaeger的docker-compose.yaml

version: '2'
services:
  jaeger-agent:
    image: jaegertracing/jaeger-agent:1.12
    stdin_open: true
    tty: true
    links:
    - jaeger-collector:jaeger-collector
    ports:
    - 6831:6831/udp
    command:
    - --reporter.grpc.host-port=jaeger-collector:14250

  jaeger-collector:
    image: jaegertracing/jaeger-collector:1.12
    environment:
      SPAN_STORAGE_TYPE: elasticsearch
      ES_SERVER_URLS: http://elasticsearch:9200
    stdin_open: true
    external_links:
    - elasticsearch/elasticsearch:elasticsearch
    tty: true

  jaeger-query:
    image: jaegertracing/jaeger-query:1.12
    environment:
      SPAN_STORAGE_TYPE: elasticsearch
      ES_SERVER_URLS: http://elasticsearch:9200
    stdin_open: true
    external_links:
    - elasticsearch/elasticsearch:elasticsearch
    tty: true
    ports:
    - 16686:16686/tcp

其中agent和collect都被設(shè)計(jì)成無狀態(tài)的，也就意味著他們可以被放在代理(如Nginx)后面而實(shí)現(xiàn)負(fù)載均衡雌澄。

幸運(yùn)的是筆者在部署過程中沒有遇見任何問題斋泄，所以也就沒有"疑難雜癥"環(huán)節(jié)了。一般來說遇到的問題都可以去issue搜到掷伙。

疑難雜癥

<trace-without-root-span>

這個(gè)錯(cuò)誤原因是: B span 是歸屬于 A span的, 但Jaeger服務(wù)器只收集到了B span, 但沒有收集到父級A span, 這時(shí)候B span就是一個(gè) without-root-span.

可能原因有下:

  • 忘記調(diào)用Finish()
  • 在程序退出時(shí)沒有調(diào)用Closer.Close(), 這會導(dǎo)致緩沖區(qū)的spans沒有被push到服務(wù)器
  • 等待一段時(shí)間, 緩沖器Span會經(jīng)過一段時(shí)間(在Golang Client里默認(rèn)是1S)才會被Push到服務(wù)器
  • 發(fā)送的Spans個(gè)數(shù)大于了QueueSize, 多余QueueSize的Spans可能會被丟棄, 這篇文檔有提到, 可以通過以下代碼配置 QueueSize: 
    report := jaegercfg.ReporterConfig{
      LogSpans:           false,
      QueueSize:          1000,
      LocalAgentHostPort: agent,
      CollectorEndpoint:  collector,
  }

有時(shí)候Jaeger上有數(shù)據(jù), 有時(shí)候沒有

由于客戶端和Jaeger-Agent之間是通過UDP協(xié)議傳輸?shù)? 所以如果測試服務(wù)器與Jager-Agent服務(wù)之間是外網(wǎng)網(wǎng)絡(luò)環(huán)境, 則可能會導(dǎo)致丟包, 通常包越大越容易丟包.

解決辦法是將Agent部署到本機(jī), 不過在開發(fā)環(huán)境為了方便也可以將客戶端配置使用Jaeger-Collector, 這時(shí)會使用HTTP協(xié)議發(fā)送Spans.

這在官方文檔中有提到:

JAEGER_AGENT_HOST defines hostname for reporting spans over UDP/Thrift. To avoid packet loss, the agent is expected to run on the same machine as the application. This var is useful when there are multiple networking namespaces on the host.

JAEGER_ENDPOINT defines the URL for reporting spans via HTTP/Thrift. This setting allows for a deployment mode where spans are submitted directly to the collector.

相關(guān)文章

最后編輯于 ：
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 人面猴
    序言：七十年代末又兵，一起剝皮案震驚了整個(gè)濱河市任柜，隨后出現(xiàn)的幾起案子，更是在濱河造成了極大的恐慌沛厨，老刑警劉巖宙地，帶你破解...
    沈念sama閱讀 216,692評論 6贊 501
  • 死咒
    序言：濱河連續(xù)發(fā)生了三起死亡事件，死亡現(xiàn)場離奇詭異逆皮，居然都是意外死亡宅粥，警方通過查閱死者的電腦和手機(jī)，發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 92,482評論 3贊 392
  • 救了他兩次的神仙讓他今天三更去死
    文/潘曉璐 我一進(jìn)店門电谣，熙熙樓的掌柜王于貴愁眉苦臉地迎上來秽梅，“玉大人，你說我怎么就攤上這事剿牺∑罂眩” “怎么了？”我有些...
    開封第一講書人閱讀 162,995評論 0贊 353
  • 道士緝兇錄：失蹤的賣姜人
    文/不壞的土叔 我叫張陵晒来，是天一觀的道長钞诡。 經(jīng)常有香客問我，道長湃崩，這世上最難降的妖魔是什么荧降？ 我笑而不...
    開封第一講書人閱讀 58,223評論 1贊 292
  • ?港島之戀（遺憾婚禮）
    正文 為了忘掉前任，我火速辦了婚禮攒读，結(jié)果婚禮上朵诫，老公的妹妹穿的比我還像新娘。我一直安慰自己薄扁，他們只是感情好剪返，可當(dāng)我...
    茶點(diǎn)故事閱讀 67,245評論 6贊 388
  • 惡毒庶女頂嫁案：這布局不是一般人想出來的
    文/花漫 我一把揭開白布。 她就那樣靜靜地躺著泌辫，像睡著了一般随夸。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上震放，一...
    開封第一講書人閱讀 51,208評論 1贊 299
  • 城市分裂傳說
    那天宾毒，我揣著相機(jī)與錄音，去河邊找鬼殿遂。 笑死诈铛，一個(gè)胖子當(dāng)著我的面吹牛乙各，可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播幢竹，決...
    沈念sama閱讀 40,091評論 3贊 418
  • 雙鴛鴦連環(huán)套：你想象不到人心有多黑
    文/蒼蘭香墨 我猛地睜開眼耳峦，長吁一口氣：“原來是場噩夢啊……” “哼！你這毒婦竟也來了焕毫？” 一聲冷哼從身側(cè)響起蹲坷，我...
    開封第一講書人閱讀 38,929評論 0贊 274
  • 萬榮殺人案實(shí)錄
    序言：老撾萬榮一對情侶失蹤，失蹤者是張志新（化名）和其女友劉穎邑飒，沒想到半個(gè)月后循签，有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體，經(jīng)...
    沈念sama閱讀 45,346評論 1贊 311
  • ?護(hù)林員之死
    正文 獨(dú)居荒郊野嶺守林人離奇死亡疙咸，尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,570評論 2贊 333
  • ?白月光啟示錄
    正文 我和宋清朗相戀三年县匠，在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片撒轮。...
    茶點(diǎn)故事閱讀 39,739評論 1贊 348
  • 活死人
    序言：一個(gè)原本活蹦亂跳的男人離奇死亡乞旦，死狀恐怖，靈堂內(nèi)的尸體忽然破棺而出题山，到底是詐尸還是另有隱情兰粉，我是刑警寧澤，帶...
    沈念sama閱讀 35,437評論 5贊 344
  • ?日本核電站爆炸內(nèi)幕
    正文 年R本政府宣布臀蛛，位于F島的核電站亲桦，受9級特大地震影響，放射性物質(zhì)發(fā)生泄漏浊仆。R本人自食惡果不足惜客峭，卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,037評論 3贊 326
  • 男人毒藥：我在死后第九天來索命
    文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望抡柿。 院中可真熱鬧舔琅，春花似錦、人聲如沸洲劣。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,677評論 0贊 22
  • 一樁弒父案，背后竟有這般陰謀
    文/蒼蘭香墨 我抬頭看了看天上的太陽囱稽。三九已至郊尝，卻和暖如春，著一層夾襖步出監(jiān)牢的瞬間战惊，已是汗流浹背流昏。 一陣腳步聲響...
    開封第一講書人閱讀 32,833評論 1贊 269
  • 情欲美人皮
    我被黑心中介騙來泰國打工， 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留，地道東北人况凉。 一個(gè)月前我還...
    沈念sama閱讀 47,760評論 2贊 369
  • 代替公主和親
    正文 我出身青樓谚鄙，卻偏偏與公主長得像，于是被迫代替她去往敵國和親刁绒。 傳聞我的和親對象是個(gè)殘疾皇子闷营，可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,647評論 2贊 354