Gin framework: implementing distributed log tracing

Introduce

Through a complete example , Based on Gin Implementing distributed log tracing in framework .

What is? API Log tracking ？

One API Requests span multiple microservices , We hope to pass a unique ID Retrieve the log of the whole link .

We will use rk-boot To start up Gin Microservices of the framework .

Please visit the following address for a complete tutorial ：

• https://rkdocs.netlify.app/cn

install

go get github.com/rookie-ninja/rk-boot
go get github.com/rookie-ninja/rk-gin

Quick start

We will create /v1/greeter API To verify , At the same time open logging, meta and tracing Middleware to achieve the purpose .

1. establish bootA.yaml & serverA.go

ServerA monitor 1949 port , And send a request to ServerB.

We go through rkginctx.InjectSpanToNewContext() Method to Tracing Information is injected into Context in , Send to ServerB.

---
gin:
  - name: greeter                   # Required
    port: 1949                      # Required
    enabled: true                   # Required
    interceptors:
      loggingZap:
        enabled: true               # Optional, enable logging interceptor
      meta:
        enabled: true               # Optional, enable meta interceptor
      tracingTelemetry:
        enabled: true               # Optional, enable tracing interceptor

// Copyright (c) 2021 rookie-ninja
//
// Use of this source code is governed by an Apache-style
// license that can be found in the LICENSE file.
package main

import (
	"context"
	"github.com/gin-gonic/gin"
	"github.com/rookie-ninja/rk-boot"
	"github.com/rookie-ninja/rk-gin/boot"
	"github.com/rookie-ninja/rk-gin/interceptor/context"
	"net/http"
)

// Application entrance.
func main() {
	// Create a new boot instance.
	boot := rkboot.NewBoot(rkboot.WithBootConfigPath("bootA.yaml"))

	// Register handler
	boot.GetEntry("greeter").(*rkgin.GinEntry).Router.GET("/v1/greeter", GreeterA)

	// Bootstrap
	boot.Bootstrap(context.Background())

	// Wait for shutdown sig
	boot.WaitForShutdownSig(context.Background())
}

// GreeterA will add trace info into context and call serverB
func GreeterA(ctx *gin.Context) {
	// Call serverB at 2008
	req, _ := http.NewRequest(http.MethodGet, "http://localhost:2008/v1/greeter", nil)

	// Inject current trace information into context
	rkginctx.InjectSpanToHttpRequest(ctx, req)

	// Call server
	http.DefaultClient.Do(req)
	
	// Respond to request
	ctx.String(http.StatusOK, "Hello from serverA!")
}

2. establish bootB.yaml & serverB.go

ServerB monitor 2008 port .

---
gin:
  - name: greeter                   # Required
    port: 2008                      # Required
    enabled: true                   # Required
    interceptors:
      loggingZap:
        enabled: true               # Optional, enable logging interceptor
      meta:
        enabled: true               # Optional, enable meta interceptor
      tracingTelemetry:
        enabled: true               # Optional, enable tracing interceptor

// Copyright (c) 2021 rookie-ninja
//
// Use of this source code is governed by an Apache-style
// license that can be found in the LICENSE file.
package main

import (
	"context"
	"github.com/gin-gonic/gin"
	"github.com/rookie-ninja/rk-boot"
	"github.com/rookie-ninja/rk-gin/boot"
	"net/http"
)

// Application entrance.
func main() {
	// Create a new boot instance.
	boot := rkboot.NewBoot(rkboot.WithBootConfigPath("bootB.yaml"))

	// Register handler
	boot.GetEntry("greeter").(*rkgin.GinEntry).Router.GET("/v1/greeter", GreeterB)

	// Bootstrap
	boot.Bootstrap(context.Background())

	// Wait for shutdown sig
	boot.WaitForShutdownSig(context.Background())
}

// GreeterB receive request from serverA and respond.
func GreeterB(ctx *gin.Context) {
	ctx.String(http.StatusOK, "Hello from serverB!")
}

3. Folder structure

.
├── bootA.yaml
├── bootB.yaml
├── go.mod
├── go.sum
├── serverA.go
└── serverB.go

0 directories, 6 files

4. start-up ServerA & ServerB

$ go run serverA.go
$ go run serverB.go

5. Go to ServerA Send a request

$ curl localhost:1949/v1/greeter
Hello from serverA!

6. Verify the log

In the logs of the two services , There will be the same traceId, Different requestId.

We can go through grep traceId To track RPC.

• ServerA

------------------------------------------------------------------------
endTime=2021-11-18T01:29:56.698997+08:00
...
ids={"eventId":"f5878390-1a5a-4bb9-8b39-bf4261864c0f","requestId":"f5878390-1a5a-4bb9-8b39-bf4261864c0f","traceId":"b2d70ab9f8207ef4a9f0c3fb1be5c22c"}
...
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE

• ServerB

------------------------------------------------------------------------
endTime=2021-11-18T01:29:56.698606+08:00
...
ids={"eventId":"273c97d2-e11a-46f5-a044-bb9c0cf64540","requestId":"273c97d2-e11a-46f5-a044-bb9c0cf64540","traceId":"b2d70ab9f8207ef4a9f0c3fb1be5c22c"}
...
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE

Concept

When we don't use, for example jaeger When calling the chain service , We hope to track the data in the distributed system through logs RPC request .

rk-boot The middleware will pass openTelemetry Library to write... To the log traceId To track RPC.

When the logging middleware is started , Original data middleware , When calling the chain middleware , The middleware will write the following three types into the log ID.

EventId

When the logging middleware is started ,EventId It will generate automatically .

---
gin:
  - name: greeter                   # Required
    port: 1949                      # Required
    enabled: true                   # Required
    interceptors:
      loggingZap:
        enabled: true

------------------------------------------------------------------------
...
ids={"eventId":"cd617f0c-2d93-45e1-bef0-95c89972530d"}
...

RequestId

When the log middleware and the original data middleware are started ,RequestId and EventId It will generate automatically , And these two ID Will be consistent .

---
gin:
  - name: greeter                   # Required
    port: 1949                      # Required
    enabled: true                   # Required
    interceptors:
      loggingZap:
        enabled: true
      meta:
        enabled: true

------------------------------------------------------------------------
...
ids={"eventId":"8226ba9b-424e-4e19-ba63-d37ca69028b3","requestId":"8226ba9b-424e-4e19-ba63-d37ca69028b3"}
...

Even if the user overwrites RequestId,EventId Will be consistent .

rkginctx.AddHeaderToClient(ctx, rkginctx.RequestIdKey, "overridden-request-id")

------------------------------------------------------------------------
...
ids={"eventId":"overridden-request-id","requestId":"overridden-request-id"}
...

TraceId

When the call chain middleware is started ,traceId It will generate automatically .

---
gin:
  - name: greeter                   # Required
    port: 1949                      # Required
    enabled: true                   # Required
    interceptors:
      loggingZap:
        enabled: true
      meta:
        enabled: true
      tracingTelemetry:
        enabled: true

------------------------------------------------------------------------
...
ids={"eventId":"dd19cf9a-c7be-486c-b29d-7af777a78ebe","requestId":"dd19cf9a-c7be-486c-b29d-7af777a78ebe","traceId":"316a7b475ff500a76bfcd6147036951c"}
...