【轉】istio原始碼分析——mixer遙測報告

小卜邪發表於2018-07-19
原始碼

image

原文：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 #187
func (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 #22
type 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

image

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 #3018
func (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               : false
context.protocol              : http
destination.port              : 8080
......
request.host                  : rds
request.method                : GET
......

資料加工 —— Preprocess

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

istio.io/istio/mixer/template/template.gen.go #33425
outBag := 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 #105
func (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 #200
func (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 #1311
logentry.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 #53
func (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次並從中獲取中位數得到。

結果：

image

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

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

github.com/jaegertracing/jaeger/pkg/queue/bounded_queue.go #76
func (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的日誌處理上，犧牲一些日誌資料，保證業務請求穩定。畢竟業務的位置是最重要的。

相關部落格

Mixer 的介面卡模型

相關文章