日志

启动 API 请求日志中间件。

安装#

go get github.com/rookie-ninja/rk-boot/v2
go get github.com/rookie-ninja/rk-gf

选项#

名字	描述	类型	默认值
gf.middleware.logging.enabled	启动日志拦截器	boolean	false
gf.middleware.logging.ignore	局部选项，忽略 API 路径	[]string	[]
gf.middleware.logging.loggerEncoding	日志格式：json 或者 console	string	console
gf.middleware.logging.loggerOutputPaths	日志文件路径	[]string	stdout
gf.middleware.logging.eventEncoding	日志格式：json 或者 console	string	console
gf.middleware.logging.eventOutputPaths	日志文件路径	[]string	stdout

概念#

我们需要提前了解两个概念。

Event
Logger

Logger#

rk-boot 使用 zap 为默认日志，lumberjack 为日志滚动库。

例子

2021-07-05T23:35:17.104+0800    INFO    boot/gf_entry.go:631   Bootstrapping GfEntry. {"eventId": "08d11a34-472a-4785-a98c-144a3417d7f0", "entryName": "greeter", "entryType": "GinEntry", "port": 8080, "interceptorsCount": 1, "swEnabled": false, "tlsEnabled": false, "commonServiceEnabled": false, "tvEnabled": false, "promPath": "/metrics", "promPort": 8080}

Event#

rk-boot 把每一个 RPC 请求视作 Event，并且使用 rk-query 中的 Event 类型来记录日志。

字段	详情
endTime	结束时间
startTime	开始时间
elapsedNano	Event 时间开销（Nanoseconds）
timezone	时区
ids	包含 eventId, requestId 和 traceId。如果元数据拦截器被启动，或者 event.SetRequest() 被用户调用，新的 RequestId 将会被使用，同时 eventId 与 requestId 会一模一样。如果调用链拦截器被启动，traceId 将会被记录。
app	包含 appName, appVersion, entryName, entryType。
env	包含 arch, domain, hostname, localIP, os 字段。这些字段来自系统环境变量（DOMAIN）。 "*" 代表环境变量为空。
payloads	包含 RPC 相关信息。
error	包含错误。
counters	通过 event.SetCounter() 来操作。
pairs	通过 event.AddPair() 来操作。
timing	通过 event.StartTimer() 和 event.EndTimer() 来操作。
remoteAddr	RPC 远程地址。
operation	RPC 名字。
resCode	RPC 返回码。
eventStatus	Ended 或者 InProgress

例子

------------------------------------------------------------------------
endTime=2021-06-25T01:30:45.144023+08:00
startTime=2021-06-25T01:30:45.143767+08:00
elapsedNano=255948
timezone=CST
ids={"eventId":"3332e575-43d8-4bfe-84dd-45b5fc5fb104","requestId":"3332e575-43d8-4bfe-84dd-45b5fc5fb104","traceId":"65b9aa7a9705268bba492fdf4a0e5652"}
app={"appName":"rk-gf","appVersion":"master-xxx","entryName":"greeter","entryType":"GfEntry"}
env={"arch":"amd64","az":"*","domain":"*","hostname":"lark.local","localIP":"10.8.0.2","os":"darwin","realm":"*","region":"*"}
payloads={"apiMethod":"GET","apiPath":"/rk/v1/healthy","apiProtocol":"HTTP/1.1","apiQuery":"","userAgent":"curl/7.64.1"}
error={}
counters={}
pairs={}
timing={}
remoteAddr=localhost:60718
operation=/rk/v1/healthy
resCode=200
eventStatus=Ended
EOE

快速开始#

1. 创建 boot.yaml#

---
gf:
  - name: greeter
    port: 8080
    enabled: true
    middleware:
      logging:
        enabled: true                                     # Optional, default: false
#        ignore: [""]                                      # Optional, default: []
#        loggerEncoding: "console"                         # Optional, default: "console"
#        loggerOutputPaths: ["logs/app.log"]               # Optional, default: ["stdout"]
#        eventEncoding: "console"                          # Optional, default: "console"
#        eventOutputPaths: ["logs/event.log"]              # Optional, default: ["stdout"]

2. 创建 main.go#

package main

import (
  "context"
  "fmt"
  "github.com/gogf/gf/v2/net/ghttp"
  "github.com/rookie-ninja/rk-boot/v2"
  "github.com/rookie-ninja/rk-gf/boot"
  "net/http"
)

func main() {
  // Create a new boot instance.
  boot := rkboot.NewBoot()

  // Register handler
  entry := rkgf.GetGfEntry("greeter")
  entry.Server.BindHandler("/v1/greeter", Greeter)

  // Bootstrap
  boot.Bootstrap(context.TODO())

  boot.WaitForShutdownSig(context.TODO())
}

func Greeter(ctx *ghttp.Request) {
  ctx.Response.WriteHeader(http.StatusOK)
  ctx.Response.WriteJson(&GreeterResponse{
    Message: fmt.Sprintf("Hello %s!", ctx.GetQuery("name").String()),
  })
}

type GreeterResponse struct {
  Message string
}

3. 验证#

发送请求

$ curl "localhost:8080/v1/greeter?name=rk-dev"
{"Message":"Hello rk-dev!"}

日志

------------------------------------------------------------------------
endTime=2022-04-15T19:11:36.096411+08:00
startTime=2022-04-15T19:11:36.096318+08:00
elapsedNano=92426
timezone=CST
ids={"eventId":"d7d49c0e-6aaa-40b9-a374-28e21425cabf"}
app={"appName":"","appVersion":"","entryName":"greeter","entryType":"GfEntry"}
env={"arch":"amd64","domain":"*","hostname":"lark.local","localIP":"192.168.1.101","os":"darwin"}
payloads={"apiMethod":"GET","apiPath":"/v1/greeter","apiProtocol":"HTTP/1.1","apiQuery":"name=rk-dev","userAgent":"curl/7.64.1"}
counters={}
pairs={}
timing={}
remoteAddr=localhost:51346
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE

Cheers#

4. JSON 格式#

---
gf:
  - name: greeter
    ...
    middleware:
      logging:
        ...
        loggerEncoding: "json"
        eventEncoding: "json"

Cheers#

5. 修改日志文件路径#

修改日志文件路径之后，默认在 1GB 大小之后，进行切割，并压缩。

---
gf:
  - name: greeter
    ...
    middleware:
      logging:
        ...
        loggerOutputPaths: ["logs/app.log"]
        eventOutputPaths: ["logs/event.log"]

Cheers#

6. 获取日志实例#

当每一次 RPC 请求进来的时候，中间件会把 RequestId（当启动了原数据中间件）注入到日志实例中。换句话说，每一个 RPC 请求，都会有一个新的 Logger 实例。

func Greeter(ctx *ghttp.Request) {
    rkgfctx.GetLogger(ctx).Info("Received request")

    ctx.Response.WriteHeader(http.StatusOK)
    ctx.Response.WriteJson(&GreeterResponse{
        Message: fmt.Sprintf("Hello %s!", ctx.GetQuery("name").String()),
    })
}

2022-04-15T19:17:01.380+0800    INFO    gf/main.go:55  Received request        {"requestId": "446c1138-1b20-48f7-a479-7b3e8a26de40"}

Cheers#

7. 修改 Event#

日志中间件会为每一个 RPC 请求创建一个 Event 实例。

用户可以添加 pairs，counters，errors。

func Greeter(ctx *ghttp.Request) {
    event := rkginctx.GetEvent(ctx)
    event.AddPair("key", "value")

    ctx.Response.WriteHeader(http.StatusOK)
    ctx.Response.WriteJson(&GreeterResponse{
        Message: fmt.Sprintf("Hello %s!", ctx.GetQuery("name").String()),
    })
}

------------------------------------------------------------------------
endTime=2022-04-15T19:17:47.088106+08:00
startTime=2022-04-15T19:17:47.08801+08:00
elapsedNano=96182
timezone=CST
ids={"eventId":"efbb5b4c-a77b-403d-b7d5-ec81662669e6","requestId":"efbb5b4c-a77b-403d-b7d5-ec81662669e6"}
app={"appName":"","appVersion":"","entryName":"greeter","entryType":"GfEntry"}
env={"arch":"amd64","domain":"*","hostname":"lark.local","localIP":"192.168.1.101","os":"darwin"}
payloads={"apiMethod":"GET","apiPath":"/v1/greeter","apiProtocol":"HTTP/1.1","apiQuery":"name=rk-dev","userAgent":"curl/7.64.1"}
counters={}
pairs={"key":"value"}
timing={}
remoteAddr=localhost:51505
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE