istio源碼分析——mixer遙測報告

原文：istio源碼分析——mixer遙測報告

聲明

1. 這篇文章需要瞭解istio，k8s，golang，envoy，mixer基礎知識
2. 分析的環境為k8s，istio版本為0.8.0

遙測報告是什麼

    這篇文章主要介紹mixer提供的一個GRPC介面，這個介面負責接收envoy上報的日誌，並將日誌在stdio和prometheus展現出來。 “遙測報告”這個詞是從istio的中文翻譯文檔借過來，第一次聽到這個詞感覺很陌生，很高大上。通過瞭解源碼，用 “日誌訂閱“ 這個詞來理解這個介面的作用會容易點。用一句話來總結這個介面的功能：我有這些日誌，你想用來做什嗎？stdio和prometheus只是這些日誌的另一種展示形式。

istio.io/istio/mixer/pkg/api/grpcServer.go #187func (s *grpcServer) Report(legacyCtx legacyContext.Context, req *mixerpb.ReportRequest) (*mixerpb.ReportResponse, error) {  ......  var errors *multierror.Error  for i := 0; i < len(req.Attributes); i++ {    ......    if i > 0 {      if err := accumBag.UpdateBagFromProto(&req.Attributes[i], s.globalWordList); err != nil {        ......        break      }    }    ......    if err := s.dispatcher.Preprocess(newctx, accumBag, reportBag); err != nil {      ......    }    ......    if err := reporter.Report(reportBag); err != nil {      ......      continue    }    ......  }  ......  if err := reporter.Flush(); err != nil {    errors = multierror.Append(errors, err)  }  reporter.Done()  ......  return reportResp, nil}

接收了什麼資料接收 —— ReportRequest

    Report介面的第二個參數是envoy上報給mixer的資料。下面的資料來源：把日誌列印到終端後再截取出來。

結構

istio.io/api/mixer/v1/report.pb.go #22type ReportRequest struct {  ......  Attributes []CompressedAttributes `protobuf:"bytes,1,rep,name=attributes" json:"attributes"`  ......  DefaultWords []string   ......  GlobalWordCount uint32 `protobuf:"varint,3,opt,name=global_word_count,json=globalWordCount,proto3" json:"global_word_count,omitempty"`}

接收的資料

req.Attributes：
[{"strings":{"131":92,"152":-1,"154":-2,"17":-7,"18":-4,"19":90,"22":92},"int64s":{"1":33314,"151":8080,"169":292,"170":918,"23":0,"27":780,"30":200},"bools":{"177":false},"timestamps":{"24":"2018-07-05T08:12:20.125365976Z","28":"2018-07-05T08:12:20.125757852Z"},"durations":{"29":426699},"bytes":{"0":"rBQDuw==","150":"AAAAAAAAAAAAAP//rBQDqg=="},"string_maps":{"15":{"entries":{"100":92,"102":-5,"118":113,"119":-3,"31":-4,"32":90,"33":-7,"55":134,"98":-6}},"26":{"entries":{"117":134,"35":136,"55":-9,"58":110,"60":-8,"82":93}}}}]

req.DefaultWords ：
["istio-pilot.istio-system.svc.cluster.local","kubernetes://istio-pilot-8696f764dd-fqxtg.istio-system","1000","rds","3a7a649f-4eeb-4d70-972c-ad2d43a680af","172.00.00.000","/v1/routes/8088/index/sidecar~172.20.3.187~index-85df88964c-tzzds.default~default.svc.cluster.local","Thu, 05 Jul 2018 08:12:19 GMT","780","/v1/routes/9411/index/sidecar~172.00.00.000~index-85df88964c-tzzds.default~default.svc.cluster.local","bc1f172f-b8e3-4ec0-a070-f2f6de38a24f","718"]

req.GlobalWordCount：
178

    第一次看到這些資料的時候滿腦子問號，和官網介紹的屬性詞彙一點關聯都看不到。在這些資料裡我們最主要關注Attributes下的類型： strings, int64s......和那些奇怪的數字。下面會揭開這些謎團。

資料轉換 —— UpdateBagFromProto

globalList

> istio.io/istio/mixer/pkg/attribute/list.gen.go #13    globalList = []string{      "source.ip",      "source.port",      "source.name",      ......    }

UpdateBagFromProto

istio.io/istio/mixer/pkg/attribute/mutableBag.go #3018func (mb *MutableBag) UpdateBagFromProto(attrs *mixerpb.CompressedAttributes, globalWordList []string) error {  messageWordList := attrs.Words  ......  lg("  setting string attributes:")  for k, v := range attrs.Strings {    name, e = lookup(k, e, globalWordList, messageWordList)    value, e = lookup(v, e, globalWordList, messageWordList)    if err := mb.insertProtoAttr(name, value, seen, lg); err != nil {      return err    }  }  lg("  setting int64 attributes:")  ......  lg("  setting double attributes:")  ......  lg("  setting bool attributes:")  ......  lg("  setting timestamp attributes:")  ......  lg("  setting duration attributes:")  ......  lg("  setting bytes attributes:")  ......  lg("  setting string map attributes:")  ......  return e}

    Istio屬性是強型別，所以在資料轉換會根據類型一一轉換。從可以看出由 DefaultWords和 globalList組成一個詞典，而 Attributes 記錄了上報資料的位置，經過 UpdateBagFromProto的處理，最終轉換為：官方的屬性詞彙。

轉換結果

connection.mtls               : falsecontext.protocol              : httpdestination.port              : 8080......request.host                  : rdsrequest.method                : GET......

資料加工 —— Preprocess

    這個方法在k8s環境下的結果是追加資料

istio.io/istio/mixer/template/template.gen.go #33425outBag := newWrapperAttrBag(  func(name string) (value interface{}, found bool) {    field := strings.TrimPrefix(name, fullOutName)    if len(field) != len(name) && out.WasSet(field) {      switch field {      case "source_pod_ip":        return []uint8(out.SourcePodIp), true      case "source_pod_name":        return out.SourcePodName, true        ......      default:        return nil, false      }    }    return attrs.Get(name)  }  ......)return mapper(outBag)

最終追加的資料

destination.labels            : map[istio:pilot pod-template-hash:4252932088]destination.namespace         : istio-system......

資料分發 —— Report

     Report會把資料分發到 Variety = istio_adapter_model_v1beta1.TEMPLATE_VARIETY_REPORT 的 Template 裡，當然還有一些過濾條件，在當前環境下會分發到 logentry 和 Metric。

istio.io/istio/mixer/pkg/runtime/dispatcher/session.go #105func (s *session) dispatch() error {  ......  for _, destination := range destinations.Entries() {    var state *dispatchState    if s.variety == tpb.TEMPLATE_VARIETY_REPORT {      state = s.reportStates[destination]      if state == nil {        state = s.impl.getDispatchState(ctx, destination)        s.reportStates[destination] = state      }    }    for _, group := range destination.InstanceGroups {      ......      for j, input := range group.Builders {        ......        var instance interface{}        //把日誌綁定到 Template裡        if instance, err = input.Builder(s.bag); err != nil{          ......          continue        }        ......        if s.variety == tpb.TEMPLATE_VARIETY_REPORT {          state.instances = append(state.instances, instance)          continue        }        ......      }    }  }  ......  return nil}

資料展示 —— 非同步Flush

    Flush是讓 logentry 和 Metric 調用各自的 adapter 對資料進行處理，由於各自的 adapter沒有依賴關係所以這裡使用了golang的協程進行非同步處理。

istio.io/istio/mixer/pkg/runtime/dispatcher/session.go #200func (s *session) dispatchBufferedReports() {    // Ensure that we can run dispatches to all destinations in parallel.    s.ensureParallelism(len(s.reportStates))    // dispatch the buffered dispatchStates we've got    for k, v := range s.reportStates {        //在這裡會把 v 放入協程進行處理      s.dispatchToHandler(v)      delete(s.reportStates, k)    }    //等待所有adapter完成    s.waitForDispatched()}

協程池

    從上面看到 v 被放入協程進行處理，其實mixer在這裡使用了協程池。使用協程池可以減少協程的建立和銷毀，還可以控制服務中協程的多少，從而減少對系統的資源佔用。mixer的協程池屬於提前建立一定數量的協程，提供給業務使用，如果協程池處理不完業務的工作，需要阻塞等待。下面是mixer使用協程池的步驟。

• 初始化協程池

    建立一個有長度的 channel，我們可以叫它隊列。

istio.io/istio/mixer/pkg/pool/goroutine.go func NewGoroutinePool(queueDepth int, singleThreaded bool) *GoroutinePool {  gp := &GoroutinePool{    queue:          make(chan work, queueDepth),    singleThreaded: singleThreaded,  }  gp.AddWorkers(1)  return gp}

• 把任務放入隊列

    把可執行檔函數和參數當成一個任務放入隊列

func (gp *GoroutinePool) ScheduleWork(fn WorkFunc, param interface{}) {    if gp.singleThreaded {        fn(param)    } else {        gp.queue <- work{fn: fn, param: param}    }}

• 讓工人工作

    想要用多少工人可以按資源分派，工人不斷從隊列擷取任務執行

func (gp *GoroutinePool) AddWorkers(numWorkers int) {  if !gp.singleThreaded {    gp.wg.Add(numWorkers)    for i := 0; i < numWorkers; i++ {      go func() {        for work := range gp.queue {          work.fn(work.param)        }        gp.wg.Done()      }()    }  }}

logentry 的 adapter 將資料列印到終端(stdio)

• 和 adapter 互動

    每個 Template 都有自己的 DispatchReport，它負責和 adapter互動，並對日誌進行展示。

istio.io/istio/mixer/template/template.gen.go #1311logentry.TemplateName: {    Name:  logentry.TemplateName,    Impl:  "logentry",    CtrCfg:   &logentry.InstanceParam{},    Variety:  istio_adapter_model_v1beta1.TEMPLATE_VARIETY_REPORT,    ......    DispatchReport: func(ctx context.Context, handler adapter.Handler, inst []interface{}) error {        ......        instances := make([]*logentry.Instance, len(inst))        for i, instance := range inst {          instances[i] = instance.(*logentry.Instance)        }        // Invoke the handler.        if err := handler.(logentry.Handler).HandleLogEntry(ctx, instances); err != nil {            return fmt.Errorf("failed to report all values: %v", err)        }        return nil    },}

• 日誌資料整理

istio.io/istio/mixer/adapter/stdio/stdio.go #53func (h *handler) HandleLogEntry(_ context.Context, instances []*logentry.Instance) error {    var errors *multierror.Error    fields := make([]zapcore.Field, 0, 6)    for _, instance := range instances {      ......      for _, varName := range h.logEntryVars[instance.Name] {          //過濾adapter不要的資料        if value, ok := instance.Variables[varName]; ok {            fields = append(fields, zap.Any(varName, value))        }      }      if err := h.write(entry, fields); err != nil {          errors = multierror.Append(errors, err)      }      fields = fields[:0]    }    return errors.ErrorOrNil()}

    每個 adapter 都有自己想要的資料，這些資料可在開機檔案 istio-demo.yaml 下配置。

apiVersion: "config.istio.io/v1alpha2"    kind: logentry    metadata:      name: accesslog      namespace: istio-system    spec:      severity: '"Info"'      timestamp: request.time      variables:        originIp: origin.ip | ip("0.0.0.0")        sourceIp: source.ip | ip("0.0.0.0")        sourceService: source.service | ""        ......

• 展示結果

    下面日誌從mixer終端截取

{"level":"info","time":"2018-07-15T09:27:30.739801Z","instance":"accesslog.logentry.istio-system","apiClaims":"","apiKey":"","apiName":"","apiVersion":"","connectionMtls":false,"destinationIp":"10.00.0.00","destinationNamespace":"istio-system"......}

問題

通過分析這個介面源碼我們發現了一些問題：

1. 介面需要處理完所有 adapter才響應返回
2. 如果協程池出現阻塞，介面需要一直等待

    基於以上二點我們聯想到：如果協程池出現阻塞，這個介面響應相應會變慢，是否會影響到業務的請求？從國人翻譯的一篇istio官方部落格Mixer 和 SPOF 的迷思裡知道，envoy資料上報是通過“fire-and-forget“模式非同步完成。但由於沒有C++基礎，所以我不太明白這裡面的“fire-and-forget“是如何?。

    因為存在上面的疑問，所以我們進行了一次類比測試。這次測試的假設條件：介面出現了阻塞，分別延遲了50ms，100ms，150ms，200ms，250ms，300ms【類比阻塞時間】，在相同壓力下，觀察對業務請求是否有影響。

• 環境： mac Air 下的 docker for k8s
• 壓測工具：hey
• 壓力：-c 50 -n 200【電腦配置不高】
• 電腦配置 i5 4G
• 壓測命令：hey -c 50 -n 200 http://127.0.0.1:30935/sleep
• 被壓測的服務代碼
• mixer介面添加延遲代碼：

func (s *grpcServer) Report(legacyCtx legacyContext.Context, req *mixerpb.ReportRequest) (*mixerpb.ReportResponse, error) {    time.Sleep(50 * time.Microsecond)    ......    return reportResp, nil}

注意

壓測的每個資料結果都是經過預熱後，壓測10次並從中擷取中位元得到。

結果：

    從我們可以看出隨著延遲的增加，業務處理的QPS也在下降。這說明在當前0.8.0版本下，協程池處理任務不夠快【進比出快】，出現了阻塞現象，會影響到業務的請求。當然我們可以通過橫向擴充mixer或增加協程池裡的工人數量來解決。 但是我覺得主要的問題出在阻塞這步上。如果沒有阻塞，就不會影響業務。

與Jaeger相互借鑒，避免阻塞

    這裡日誌資料處理情境和之前瞭解的Jaeger很像。Jaeger和mixer處理的都是日誌資料，所以它們之間可以相互借鑒。Jaeger也有它自己的協程池，而且和mixer的協程池思想是一樣的，雖然實現細節不一樣。那如果遇到 進比出快的情況Jaeger是如何處理的呢？具體的情境可以看這裡。

github.com/jaegertracing/jaeger/pkg/queue/bounded_queue.go #76func (q *BoundedQueue) Produce(item interface{}) bool {    if atomic.LoadInt32(&q.stopped) != 0 {        q.onDroppedItem(item)        return false    }    select {    case q.items <- item:        atomic.AddInt32(&q.size, 1)        return true    default:        //丟掉資料        if q.onDroppedItem != nil {            q.onDroppedItem(item)        }        return false    }}

    上面是Jaeger的源碼，這裡和mixer 的 ScheduleWork 相對應，其中一個區別是如果Jaeger的隊列 items滿了，還有資料進來，資料將會被丟掉，從而避免了阻塞。這個思路也可以用在mixer的Tlog上，犧牲一些日誌資料，保證業務請求穩定。畢竟業務的位置是最重要的。

相關部落格

Mixer 的適配器模型