介绍
通过一个完整例子,在 gorilla/mux 微服务中添加 API 日志中间件。
什么是日志拦截器/中间件?
日志拦截器会对每一个 API 请求记录日志。
我们将会使用 rk-boot 来启动 gorilla/mux 微服务。
请访问如下地址获取完整教程:https://github.com/rookie-ninja/rk-mux
安装
代码语言:go复制go get github.com/rookie-ninja/rk-boot/mux
快速开始
rk-boot 默认集成如下三个开源库。
- uber-go/zap 作为底层的日志库。
- logrus 作为日志滚动。
- loki 作为日志远程存储。
1.创建 boot.yaml
boot.yaml 文件描述了 GoFrame 框架启动的原信息,rk-boot 通过读取 boot.yaml 来启动 gorilla/mux。
为了验证,我们同时启动了 commonService。commonService 里包含了一系列通用 API。
详情: CommonService
代码语言:yaml复制---
mux:
- name: greeter # Required
port: 8080 # Required
enabled: true # Required
commonService:
enabled: true # Optional, enable common service
interceptors:
loggingZap:
enabled: true # Optional, enable logging interceptor
2.创建 main.go
代码语言:go复制// 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"
"fmt"
"github.com/rookie-ninja/rk-boot"
"github.com/rookie-ninja/rk-boot/mux"
"github.com/rookie-ninja/rk-mux/interceptor"
"net/http"
)
func main() {
// Create a new boot instance.
boot := rkboot.NewBoot()
// Register handler
entry := rkbootmux.GetMuxEntry("greeter")
entry.Router.NewRoute().Methods(http.MethodGet).Path("/v1/greeter").HandlerFunc(Greeter)
// Bootstrap
boot.Bootstrap(context.TODO())
boot.WaitForShutdownSig(context.TODO())
}
func Greeter(writer http.ResponseWriter, request *http.Request) {
rkmuxinter.WriteJson(writer, http.StatusOK, &GreeterResponse{
Message: fmt.Sprintf("Hello %s!", request.URL.Query().Get("name")),
})
}
type GreeterResponse struct {
Message string
}
3.文件夹结构
代码语言:txt复制$ tree
.
├── boot.yaml
├── go.mod
├── go.sum
└── main.go
0 directories, 4 files
4.启动 main.go
代码语言:txt复制$ go run main.go
2022-02-11T15:43:33.130 0800 INFO boot/mux_entry.go:643 Bootstrap muxEntry {"eventId": "1a7f1d5a-13d7-4796-8108-939285d3ec13", "entryName": "greeter", "entryType": "Mux"}
------------------------------------------------------------------------
endTime=2022-02-11T15:43:33.130747 08:00
startTime=2022-02-11T15:43:33.130545 08:00
elapsedNano=202290
timezone=CST
ids={"eventId":"1a7f1d5a-13d7-4796-8108-939285d3ec13"}
app={"appName":"rk","appVersion":"","entryName":"greeter","entryType":"Mux"}
env={"arch":"amd64","az":"*","domain":"*","hostname":"lark.local","localIP":"10.8.0.2","os":"darwin","realm":"*","region":"*"}
payloads={"commonServiceEnabled":true,"commonServicePathPrefix":"/rk/v1/","muxPort":8080}
counters={}
pairs={}
timing={}
remoteAddr=localhost
operation=Bootstrap
resCode=OK
eventStatus=Ended
EOE
5.验证
我们发送 CommonService 自带的 /rk/v1/healthy 请求。
代码语言:txt复制$ curl -X GET localhost:8080/rk/v1/healthy
{
"healthy": true
}
发送请求到 /v1/greeter。
代码语言:txt复制$ curl "localhost:8080/v1/greeter?name=rk-dev"
{"Message":"Hello rk-dev!"}
EventLog 会默认输出到 stdout。
下面的日志格式来自 rk-query ,用户也可以选择 JSON 格式,我们稍后会介绍。
代码语言:txt复制------------------------------------------------------------------------
endTime=2022-02-11T15:44:20.00081 08:00
startTime=2022-02-11T15:44:20.000749 08:00
elapsedNano=61165
timezone=CST
ids={"eventId":"c786ff55-78b4-4c44-a268-581aa16def16"}
app={"appName":"rk","appVersion":"","entryName":"greeter","entryType":"Mux"}
env={"arch":"amd64","az":"*","domain":"*","hostname":"lark.local","localIP":"10.8.0.2","os":"darwin","realm":"*","region":"*"}
payloads={"apiMethod":"GET","apiPath":"/v1/greeter","apiProtocol":"HTTP/1.1","apiQuery":"name=rk-dev","userAgent":"curl/7.64.1"}
counters={}
pairs={}
timing={}
remoteAddr=127.0.0.1:57341
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE
修改日志格式
我们可以通过修改 boot.yaml 来修改日志格式。
目前支持 json 和 console 两种格式,默认为 console。
通过修改 eventLoggerEncoding 的值为 json,我们可以把日志的输出为 JSON 格式。
代码语言:yaml复制mux:
- name: greeter # Required
port: 8080 # Required
enabled: true # Required
commonService:
enabled: true # Optional, enable common service
interceptors:
loggingZap:
enabled: true # Optional, enable logging interceptor
zapLoggerEncoding: "json" # Override to json format, option: json or console
eventLoggerEncoding: "json" # Override to json format, option: json or console
代码语言:json复制{
"endTime":"2022-02-11T15:45:27.481 0800",
"startTime":"2022-02-11T15:45:27.480 0800",
"elapsedNano":60615,
"timezone":"CST",
"ids":{
"eventId":"f497d8bb-578f-485a-977b-7de7fc5b560e"
},
"app":{
"appName":"rk",
"appVersion":"",
"entryName":"greeter",
"entryType":"Mux"
},
"env":{
"arch":"amd64",
"az":"*",
"domain":"*",
"hostname":"lark.local",
"localIP":"10.8.0.2",
"os":"darwin",
"realm":"*",
"region":"*"
},
"payloads":{
"apiMethod":"GET",
"apiPath":"/v1/greeter",
"apiProtocol":"HTTP/1.1",
"apiQuery":"name=rk-dev",
"userAgent":"curl/7.64.1"
},
"error":{},
"counters":{},
"pairs":{},
"timing":{},
"remoteAddr":"127.0.0.1:61646",
"operation":"/v1/greeter",
"eventStatus":"Ended",
"resCode":"200"
}
修改日志路径
通过修改 eventLoggerOutputPaths 的值,可以指定输出路径。
日志默认在 1GB 之后,进行切割,并压缩。
代码语言:yaml复制---
mux:
- name: greeter # Required
port: 8080 # Required
enabled: true # Required
commonService:
enabled: true # Optional, enable common service
interceptors:
loggingZap:
enabled: true # Optional, enable logging interceptor
zapLoggerOutputPaths: ["logs/app.log"] # Override output paths
eventLoggerOutputPaths: ["logs/event.log"] # Override output paths
代码语言:txt复制.
├── boot.yaml
├── go.mod
├── go.sum
├── logs
│ └── event.log
└── main.go
直接写入到 Loki(远程日志存储)
loki 是一款云原生日志存储,搜索开源服务。比起 ElasticSearch 更轻便,存储成本非常低(可以使用云对象存储)。
ElasticSearch 的搜索引擎,存储引擎非常先进,不过运维难度,价格,使用简易度,配置的门槛较高,不适合简单服务。
loki 使用了传统的 Agent 模式来收集日志。rk-boot 在内部使用了一个 loki-client 直接把日志传送到 Loki 服务中。
之所所以这么使用,一个方面是为了消除 Agent 配置带来的麻烦。其次,就是消除了多行日志的情况,比如,打印 Panic 信息时,我们必须在 Agent 里配置一个正则表达式,来告诉 Agent 把 Panic 整合到一个 Stream 发送到 Loki 服务。
不过,这种配置非常麻烦。
如果是大量日志的情况,可能会影响速度。虽然 rk-boot 异步发送日志到 Loki,不过因为涉及到锁,速度难免会受到影响。所以,如果是大量日志情况,可以使用传统 Agent 模式。
1.boot.yaml
额外定义 zapLogger, eventLogger, mux.logger.zapLogger & mux.logger.eventLogger。
代码语言:yaml复制zapLogger:
- name: zap-logger
loki:
enabled: true
eventLogger:
- name: event-logger
loki:
enabled: true
mux:
- name: greeter # Required
port: 8080 # Required
enabled: true # Required
logger:
zapLogger: zap-logger # Optional, reference of zapLogger entry name
eventLogger: event-logger # Optional, reference of eventLogger entry name
interceptors:
loggingZap:
enabled: true # Optional, enable logging interceptor
2.本地启动 Loki
为了验证,我们在本地使用 Docker 启动 Loki。
代码语言:txt复制$ docker run -d --name=loki -p 3100:3100 grafana/loki
3.本地启动 Grafana
我们使用 Grafana 搜索查看日志。
代码语言:txt复制$ docker run -p 3000:3000 --name grafana grafana/grafana
在 Grafana 里添加 Loki 数据源
Grafana 只是一个 Web UI 工具,为了能看到数据报表,我们告诉 Grafana 在哪里寻找 Loki。
因为 Grafana 运行在 Docker 中,所以,我们不使用 localhost:9090,而是,host.docker.internal:9090。
4.启动 main.go & 发送请求
代码语言:txt复制$ go run main.go
$ curl "localhost:8080/v1/greeter?name=rk-dev"
5.在 Grafana 中查看日志
6.完整 Loki 配置
代码语言:yaml复制---
eventLogger:
- name: event-logger # Required
loki:
enabled: true # Optional, default: false
addr: localhost:3100 # Optional, default: localhost:3100
path: /loki/api/v1/push # Optional, default: /loki/api/v1/push
username: "" # Optional, default: ""
password: "" # Optional, default: ""
maxBatchWaitMs: 3000 # Optional, default: 3000
maxBatchSize: 1000 # Optional, default: 1000
insecureSkipVerify: false # Optional, default: false
labels: # Optional, default: empty map
my_label_key: my_label_value
zapLogger:
- name: zap-logger # Required
loki:
enabled: true # Optional, default: false
addr: localhost:3100 # Optional, default: localhost:3100
path: /loki/api/v1/push # Optional, default: /loki/api/v1/push
username: "" # Optional, default: ""
password: "" # Optional, default: ""
maxBatchWaitMs: 3000 # Optional, default: 3000
maxBatchSize: 1000 # Optional, default: 1000
insecureSkipVerify: false # Optional, default: false
labels: # Optional, default: empty map
my_label_key: my_label_value
概念
验证了日志拦截器,我们来具体讲一下 rk-boot 提供的日志拦截器都有哪些功能。
我们需要提前了解两个概念。
- EventLogger
- ZapLogger
ZapLogger
用于记录错误/详细日志,用户可以获取本次 RPC 调用的 ZapLogger 实例,进行日志写入,每个 RPC 的 ZapLogger 实例都包含当前的 RequestId。
代码语言:txt复制2022-02-11T15:47:04.571 0800 INFO boot/mux_entry.go:643 Bootstrap muxEntry {"eventId": "7b995b92-d77b-4fed-861d-cbfd53738768", "entryName": "greeter", "entryType": "Mux"}
EventLogger
RK 启动器把每一个 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, az, domain, hostname, localIP, os, realm, region. realm, region, az, domain 字段。这些字段来自系统环境变量(REALM,REGION,AZ,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=2022-02-11T15:44:20.00081 08:00
startTime=2022-02-11T15:44:20.000749 08:00
elapsedNano=61165
timezone=CST
ids={"eventId":"c786ff55-78b4-4c44-a268-581aa16def16"}
app={"appName":"rk","appVersion":"","entryName":"greeter","entryType":"Mux"}
env={"arch":"amd64","az":"*","domain":"*","hostname":"lark.local","localIP":"10.8.0.2","os":"darwin","realm":"*","region":"*"}
payloads={"apiMethod":"GET","apiPath":"/v1/greeter","apiProtocol":"HTTP/1.1","apiQuery":"name=rk-dev","userAgent":"curl/7.64.1"}
counters={}
pairs={}
timing={}
remoteAddr=127.0.0.1:57341
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE
日志中间件选项
名字 | 描述 | 类型 | 默认值 |
---|---|---|---|
mux.interceptors.loggingZap.enabled | 启动日志拦截器 | boolean | false |
mux.interceptors.loggingZap.zapLoggerEncoding | 日志格式:json 或者 console | string | console |
mux.interceptors.loggingZap.zapLoggerOutputPaths | 日志文件路径 | []string | stdout |
mux.interceptors.loggingZap.eventLoggerEncoding | 日志格式:json 或者 console | string | console |
mux.interceptors.loggingZap.eventLoggerOutputPaths | 日志文件路径 | []string | stdout |
获取 RPC 日志实例
每一次 RPC 请求进来的时候,拦截器会把 RequestId(当启动了原数据拦截器)注入到日志实例中。
换句话说,每一个 RPC 请求,都会有一个新的 Logger 实例。我们来看看如何为一个 RPC 请求,记录 ZapLogger 日志。
通过 rkmuxctx.GetLogger(ctx) 方法获取本次请求的日志实例。
代码语言:go复制func Greeter(writer http.ResponseWriter, request *http.Request) {
rkmuxctx.GetLogger(request, writer).Info("Request received")
rkmuxinter.WriteJson(writer, http.StatusOK, &GreeterResponse{
Message: fmt.Sprintf("Hello %s!", request.URL.Query().Get("name")),
})
}
日志打印了出来!
代码语言:txt复制2022-02-11T15:49:33.513 0800 INFO mux/main.go:33 Request received
修改 Event
日志拦截器会为每一个 RPC 请求创建一个 Event 实例。
用户可以添加 pairs,counters,errors。
通过 rkmuxctx.GetEvent(ctx) 获取本次 RPC 的 Event 实例。
代码语言:go复制func Greeter(writer http.ResponseWriter, request *http.Request) {
event := rkmuxctx.GetEvent(request)
event.AddPair("key", "value")
rkmuxinter.WriteJson(writer, http.StatusOK, &GreeterResponse{
Message: fmt.Sprintf("Hello %s!", request.URL.Query().Get("name")),
})
}
Event 里增加了 pairs={"key":"value"}!
代码语言:txt复制------------------------------------------------------------------------
endTime=2022-02-11T15:50:19.286491 08:00
startTime=2022-02-11T15:50:19.286432 08:00
elapsedNano=59508
timezone=CST
ids={"eventId":"382e39dd-c258-4347-b833-c8e391b05777"}
app={"appName":"rk","appVersion":"","entryName":"greeter","entryType":"Mux"}
env={"arch":"amd64","az":"*","domain":"*","hostname":"lark.local","localIP":"10.8.0.2","os":"darwin","realm":"*","region":"*"}
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=127.0.0.1:63859
operation=/v1/greeter
resCode=200
eventStatus=Ended
EOE