Tracing with Opentelemetry

簡介

Opentelemetry (以下簡稱OTel)是由OpenTracing、 OpenCensus兩者合併而來,提供了 API, SDK與眾多的集合工具,讓我們可以產生並收集系統相關的觀測資料,基本上OTel是一個規範,所以不少的產品如Elastic APM, Watch Dog都會朝併容OTel的方向進行。

OTel至少涵蓋了LogTraceMetric,但在此僅就Tracing的部份說說我看到的解決方式,其他的部份,也許下次吧…

坦白說,我覺得具有tracing功能的log,是一個系統不可或缺的架構內容,當然tracing 與 logging是兩件事,但不具tracing的log,在查問題時是一場困難的挑戰。

自前端發送request起,就應該傳送一個可追踪的id,後端要能承接此id,並在之後的每一筆相關的log都能標示出此id,所以相關的log都能一次找出來;這個需求在從前單一Server的情形下不難辦到,但目前大家的架構都轉往microservices,不同service間要傳遞這個可追踪的id,不免要花些工夫。

還好有Opentelemetry。

演示題目說明

用下列系統做一個範例,Client->DepartmentSv->Rest/DB/MessageQueue->EmployeeSv

同時包含了下列幾項需求

  1. 前端到後端
  2. 後端中不同Service互相呼叫(http)
  3. 後端對DB
  4. Message Queue的pub/sub

要做出能貫穿全部的Trace Log,缺一個都不算完整。

Screen Shot 2023-01-18 at 16.38.06

1. 啟用 jaegertracing 全家桶

利用docker-compose 起動全家桶,OpenTelemetry要用的全部都包了。詳細的說明可以參考jaeger getting-started

  jaeger:
    image: jaegertracing/all-in-one:latest
    container_name: jaegertracing
    environment:
      - COLLECTOR_OTLP_ENABLED=true
      - COLLECTOR_ZIPKIN_HOST_PORT=9411
    ports:
      - 5775:5775/udp
      - 6831:6831/udp
      - 6832:6832/udp
      - 5778:5778
      - 16686:16686
      - 14250:14250
      - 14268:14268
      - 14269:14269
      - 4317:4317
      - 4318:4318
      - 9411:9411

2. 使用environment variables做auto Instrumentation

下載opentelemetry-javaagent.jar

加入service application做為啟動時的javaagent,OTel會自行找合適的斷點送出新span的要求。這裡我們使用了環境變數JAVA_TOOL_OPTIONS來做為載入的機制。

在各開發的系統加入下列環境變數內容

1. deparment service

JAVA_TOOL_OPTIONS=-javaagent:/Users/elliot/IdeaProjects/springkind/multi/agent/opentelemetry-javaagent.jar
OTEL_EXPORTER_JAEGER_ENDPOINT=http://localhost:14250
OTEL_METRICS_EXPORTER=none
OTEL_SERVICE_NAME=department-sv
OTEL_TRACES_EXPORTER=jaeger

2. employee service

JAVA_TOOL_OPTIONS=-javaagent:/Users/elliot/IdeaProjects/springkind/multi/agent/opentelemetry-javaagent.jar
OTEL_EXPORTER_JAEGER_ENDPOINT=http://localhost:14250
OTEL_METRICS_EXPORTER=none
OTEL_SERVICE_NAME=employee-sv
OTEL_TRACES_EXPORTER=jaeger

在IDE裡可以這樣設定

Screen Shot 2023-01-18 at 16.59.41

環境變數說明

JAVA_TOOL_OPTIONS,這是一個JVM的變數,在建立JVM時會直接參照,之後這機制會拿來建spring boot docker image。

OTEL_SERVICE_NAME則是application在trace裡要顯示的名稱,所以不同的service要用不同的設定

OTEL_EXPORTER_JAEGER_ENDPOINT則是指到全家桶的位置

OTEL_METRICS_EXPORTER在這個例子裡,我們不處理metric的資料,所以暫時不輸出metrics data

OTEL_TRACES_EXPORTER則是指出採用了jaeger solution.

3. 沒有第3步了!

沒看錯,沒有必要的第三步了

演示開始

在開始前要另外說明,從General SDK Configuration中的OTEL_PROPAGATORS可用的值可知道OTel支援了[W3C Trace Context](https://www.w3.org/TR/trace-context/),也就是如果前端以合於trace context的名稱與內容傳入trace id,後端的系統可以延用此trace id,這也讓我們可以自行控制trace id。

以下以postman為例,在header裡加入traceparent

Screen Shot 2023-01-19 at 08.23.31

之後相關的trace與log就可以0af7651916cd43dd8448eb211c80319d做為trace id記錄。

另外為了方便在log裡顯示,可以修改application.yml

spring:
  application:
    name: employee-svc
logging:
  pattern:
    level: "%5p [${spring.application.name:},%X{trace_id:-},%X{span_id:-}]"

這樣就可以自mdc裡取出trace_id與span_id。

說了這麼多,還是試打一下吧,完成後可以透過jaeger提供的介面查詢,全家桶的設定為http://localhost:16686/

如我們所預期的,可以見到0af7651916cd43dd8448eb211c80319d完整的執行經過,包含了kafka的pub/sub情形

Screen Shot 2023-01-19 at 08.35.58

加演內容:log

先前改了logger level的pattern,所以在spring的log中可見下列內容

department service

2023-01-19T08:35:20.870+08:00  INFO [department-svc,0af7651916cd43dd8448eb211c80319d,506dd4b58b62a373] 22708 --- [ctor-http-nio-4] tw.elliot.depart.ctrl.DepartmentCtrl     : Send test1 to kafka
2023-01-19T08:35:20.955+08:00  INFO [department-svc,0af7651916cd43dd8448eb211c80319d,506dd4b58b62a373] 22708 --- [ctor-http-nio-4] o.a.k.clients.producer.ProducerConfig    : ProducerConfig values: 
2023-01-19T08:35:21.978+08:00  INFO [department-svc,0af7651916cd43dd8448eb211c80319d,506dd4b58b62a373] 22708 --- [ctor-http-nio-4] tw.elliot.depart.ctrl.DepartmentCtrl     : WebClient Check trace_id should be 0af7651916cd43dd8448eb211c80319c

employee service

2023-01-19T08:35:22.096+08:00  INFO [employee-svc,0af7651916cd43dd8448eb211c80319d,30c38f5ba70ceddf] 22699 --- [ntainer#0-0-C-1] tw.elliot.emp.consumer.SpringConsumer    : Got a message from kafka: [test1]
2023-01-19T08:35:23.457+08:00 ERROR [employee-svc,0af7651916cd43dd8448eb211c80319d,240f2f50726d2dc6] 22699 --- [ctor-http-nio-2] tw.elliot.emp.ctrl.EmployeeCtrl          : findByDepId - [dep01]

相關的log也都顯示了同一個trace id,

這個部份當我們將log送入logstash時就可以拆解,方便在elasticsearch裡查詢。之後前後端有任何問題,都可以直接以trace id溝通,不用猜是哪一筆有問題。

發佈留言

發佈留言必須填寫的電子郵件地址不會公開。 必填欄位標示為 *

這個網站採用 Akismet 服務減少垃圾留言。進一步了解 Akismet 如何處理網站訪客的留言資料