乐趣区

关于go:腾讯-tRPCGo-教学5filtercontext-和日志组件

本文咱们来介绍一下在 tRPC 中的 filter 机制、context 用法,以及在相干机制上能够实现的 tracing log 能力。

说实话,这一部份是我集体最不喜爱的 tRPC 的实现模式,不过这不障碍咱们应用它——只有把它封装成让人更为难受的模式也未尝不可。


系列文章

  • 腾讯 tRPC-Go 教学——(1)搭建服务
  • 腾讯 tRPC-Go 教学——(2)trpc HTTP 能力
  • 腾讯 tRPC-Go 教学——(3)微服务间调用
  • 腾讯 tRPC-Go 教学——(4)tRPC 组件生态和应用
  • 腾讯 tRPC-Go 教学——(5)filter、context 和日志组件
  • …… 还会有更多,敬请期待 ……

tracelog 代码简介

本文所波及的内容,都能够应用笔者的一个 tracelog package 来作辅助解说。这个包所提供的性能有:

  1. 基于 tRPC context 和 message 机制 (下文阐明),在日志中蕴含 trace ID 信息便于跟踪一个调用链
  2. 基于 tRPC filter 机制,跨微服务传递 trace ID 并主动实现 1
  3. 通过日志记录每次主和谐被调的整体状况

具体的实现办法,本文放在最初,等讲完波及的 tRPC 机制之后再作阐明。


filter 机制

在 gRPC 中,实现了拦截器 interceptor 性能;相似的在驰名的 HTTP 框架 gin 中,也提供了中间件模式。这两种机制的性能十分相似,都是在作为 server 时收到申请、以及作为 client 时发送申请时,优先对数据进行一些解决、查看等逻辑,非常适合用来做一些非业务逻辑,比方:

  • 接口鉴权
  • 日志记录
  • 监控上报
  • ……

在 tRPC 中,相似的机制被称为 filter 过滤器 / 拦截器。在 gRPC 中 interceptor 有四种,但 tRPC 中简化为 server filter 和 client filter 两种。

咱们能够参考 tracelog filter.go 文件的 RegisterTraceLogFilter 函数。该函数向 tRPC 框架注册了一个名为 tracelog (参见 tracelog.FilterName 常量) 的 filter,蕴含 server filter 和 client filter。

函数格局

其中 server filter 回调的格局为:

func(ctx context.Context, req any, next filter.ServerHandleFunc) (rsp any, err error)

而 client filter 为:

func(ctx context.Context, req, rsp any, next filter.ClientHandleFunc) error

实现

在 filter 函数中,咱们能够撰写代码察看以后的调用状况。不论是 server 还是 client filter 函数,都蕴含一个 next 参数。相似于 gRPC 的 interceptor 机制,tRPC 也是应用相似于堆栈模式组织各 filter 的,对于每一个 filter 函数,该当将 next 视作真正的业务解决逻辑。在 next 之前解决业务前置逻辑,在 next 之后撰写业务后置逻辑。

比方最简略的例子——打印一下耗时日志:

func clientFilter(ctx context.Context, req, rsp any, next filter.ClientHandleFunc) error {start := time.Now()
    err := next(ctx, req, rsp)
    log.DebugContextf(ctx, "ela: %v, err: %v", time.Since(start), err)
    return err
}

filter.Register 函数所传递的两个 filter 函数均不应为空,如果 filter 逻辑就是透传即可,那么就简略实现:

func emptyServerFilter(ctx context.Context, req any, next filter.ServerHandleFunc) (any, error) {return next(ctx, req)
}

tRPC 也内置了一些罕用的 filter,导入形式为:

import _ "trpc.group/trpc-go/trpc-filter/$(filter_name)"

理论的仓库地址为: github.com/trpc-ecosystem/go-filter

其中咱们在业务中必备的 filter 是 recovery,避免业务逻辑 panic 导致服务重启。其余的比方 debuglog 和 validation 咱们也用,但绝对少。读者能够查阅文档后再选用。

filter 配置

能够看到,filter 分 server 侧和 client 侧。首先在代码中须要导入相干的包,从而在二进制中反对相干能力。目前大部分官网默认的 filter 是通过 init 函数的形式注册到 trpc 框架中的。

让咱们以前文给出的几个服务作为例子,配置形式是在 trpc_go.yaml 的 serverclient 侧各有一个名为 filter 的字符串数组类型的字段,咱们能够将 filter 按名称配置在此处,别离对应 server filter 和 client filter,此处的配置对所有的 server / client 失效。请留神,filter 配置的程序也会影响 trpc 框架调用 filter 的程序。


context 和 “message”

从 Go 1.13 版开始,以 net/http 包的 NewRequestWithContext 函数为标记,开始全面反对 context 机制。gRPC 很快跟进,在所有 client 和 server 端的实现上,均蕴含 ctx 参数。作为后浪的 tRPC,也继承了这一个性。

超时管制

在 tRPC 中有多个超时配置。咱们以之前的文章中提过的 http-auth-server 的 trpc_go.yaml 文件为例:

server:
  timeout: 2000
  service:
    - name: demo.httpauth.Auth
      nic: eth0
      port: 8001
      network: tcp
      protocol: http
      timeout: 1800

client:
  timeout: 3000
  service:
    - name: demo.account.User
      target: ip://127.0.0.1:8002
      network: tcp
      protocol: trpc
      timeout: 1000

在上述配置文件中的超时工夫单位均为毫秒,别离有:

配置项 阐明
server.service[n].timeout 具体 server 端的解决超时工夫
server.timeout 当上一配置缺失时,所对应的缺省超时工夫
client.service[n].timeout 发动一个 client 调用的超时工夫
client.timeout 当上一配置缺失时,所对应的缺省超时工夫

其次,下文中会提及 tRPC 的 metadata,而 tRPC 发动调用的时候,超时工夫也会通过 metadata 的模式往下进一步传递。如果你的上游服务也是 tRPC 的话,那么要留神:超时工夫还可能受到上游的限度。

此外,开发者也能够在代码中显式地为 context 设置一个超时工夫,比方通过 WithTimeoutWithDeadline 函数,取得一个附带超时工夫的 context,传递给 tRPC 框架用于发动主调。

这么多的超时工夫,到底取哪一个呢?

  • 答:tRPC 框架在调用 server 端业务代码,以及发动 client 主调时,均会抉择上述超时工夫中最短的一个。

codec.Msg

在 tRPC 中对 context 的应用逻辑,请参见代码的 codec 包实现。tRPC 应用 codec 包,提供了扩大任意第三方编码格局的能力。

如果读者须要实现除了默认反对的几种协定之外的其余编解码格局(比方腾讯 tars 所应用的 jce),能够浏览相干的 README 并进行实现。不过对于本文而言,咱们更关注 tRPC 应用 message 性能所提供的更多能力。所谓的 “message”,指的是 codec.Msg 接口类型,读者能够查看这个接口的实现。

正如前文所述,tRPC 的所有 server 端办法中,第一个函数均为 context.Context 类型,而 tRPC 基于 context 的 WithValue 办法,内置了 codec.Msg 类型数据。只有你的 server 办法是通过 tRPC 框架调用的,那么开发者均能够应用 codec.EnsureMessage 函数,从 context 中提取出 Msg 实例。

Msg 接口的性能很多,读者能够一一理解。本文咱们只介绍 Msg 的其中几个最罕用的性能:

  • metadata
  • 超时机制
  • 日志器和 tracing

日志

在 tRPC 中,日志的 tracing(跟踪)次要是通过在写入日志时,额定增加若干的信息。tRPC 的 log 底层呢是应用 zap 来实现的,不过 zap 尽管是结构化的日志,然而 tRPC 裸露进去的实际上更多的是非结构化的日志接口。

性能

以 INFO 级别为例,tRPC 有四种日志函数格局:

log.Info(xxx, xxx...)
log.Infof("format", xxx...)
log.InfoContext(ctx, xxx, xxx...)
log.InfoContextf(ctx, "format", xxx...)

其中 log.Info 的输入成果相似于 fmt.Print 函数,而 log.Infof 则相似于 fmt.Printf。而带 ctx 参数的另外两个函数,则能够在后面两个日志函数的根底上,输入在 ctx 中携带的一些额定信息。往往咱们能够在 ctx 中给 tRPC 的日志器携带 tracing 数据,此时利用带 ctx 的日志函数就能够打印出这些数据了。

至于如何携带信息,咱们在本文最初对于 tracelog 的实现中再作阐明。

Fatal 级别日志

在 tRPC 中,日志的级别从低到高别离是: TRACE、DEBUG、INFO、WARN、ERROR、FATAL。其中 trace 级别在理论业务中非常少用。

Fatal 级别的日志比拟非凡,它会先实现日志的输入,而后再退出服务。如果在业务中遇到了某些导致服务无奈运行上来的状况,咱们不应用 panic 函数,而是应用 log.Fatal 系列调用,保留足够的现场信息之后再退出服务。

配置

tRPC 日志的 官网文档,集体感觉是一众 tRPC 文档中最详尽和清晰的文档之一了。简略而言,就是开发者只有配置 trpc_go.yaml 中的 plugins.log.default 中的相干字段就能够了。我集体罕用的配置如下:

plugins:
  log:
    default:
      - writer: console
        level: fatal       # 规范输入我个别就不打日志了, 只保留重大异样
        formatter: console
      - writer: file
        level: debug       # 本地文件的日志级别看状况, 调试 / 测试用 debug, 失常线上环境用 info, 如果日志量太大则应用 warn 或 error
        formatter: json    # 文件日志我喜爱用 JSON, 便于各种日志采集器采集
        formatter_config:  # 格式化配置
          time_fmt: 2006-01-02 15:04:05  # 日期格式化, 与 go time 的格式化格局雷同
          time_key: time   # 日志工夫字段名称,不填默认 "T",填 "none" 可禁用此字段
          level_key: level # 日志级别字段名称,不填默认 "L",填 "none" 可禁用此字段
          name_key: none   # 日志名称字段名称,不填默认 "N",填 "none" 可禁用此字段
          caller_key: caller   # 日志调用方字段名称,不填默认 "C",填 "none" 可禁用此字段
          message_key: message # 日志音讯体字段名称,不填默认 "M",填 "none" 可禁用此字段
          stacktrace_key: stack_trace  # 日志堆栈字段名称,不填默认 "S",填 "none" 可禁用此字段
        writer_config:
          log_path: ./log/   # 示意日志放在哪个目录下
          filename: trpc.log # 示意日志文件的根底名称
          write_mode: 2      # 日志写入模式,1- 同步,2- 异步,3- 极速 (异步抛弃), 不配置默认异步模式
          roll_type: size    # 文件滚动类型,time 为按工夫滚动, size 示意按文件大小滚动
          max_size: 1000     # 单位: MB
          max_backups: 10    # 最大日志文件数, 超出则主动删除 

更具体的字段阐明请参照 官网文档。


metadata

在 gRPC 中,通过 incoming metadata 和 outgoing metadata 的机制,能够在申请 / 响应包体数据之外,额定传输与业务不间接相干的元数据。

在 tRPC 中,则应用 server metadata 的机制进行传递(还有一个 client metadata,然而笔者没有齐全把握其日常用法,就临时不讲了)。tRPC 的 metadata 也是基于 codec.Msg 接口进行封装的,然而业务开发者能够不须要太关注这个 feature,感兴趣的话再认真钻研就能够了。

理论利用中,metadata 个别是用来承载非业务数据,比如说可观测性参数、数据埋点、用户画像、标签、染色信息等等,而不是具体某个业务的逻辑数据。

集体不倡议在业务逻辑中间接操作 metadata,业务代码专一做业务逻辑就行了。至于 metadata 的操作形式,能够通过 filter 机制来实现。只有上下游都是 trpc,那么 metadata 都可能很顺畅地传输。


tracelog 的实现逻辑

下面咱们理解完了基础知识,可能读者还是感觉有点懵。没关系,让咱们来看看全文作为理论例子的 tracelog 是如何实现的。笔者的这个 tracelog 工具,思路借鉴了我所在团队所开发的的一个同名 filter,然而在实现上齐全不同。

trace ID

在 tracelog 中实现 trace ID 的逻辑可参见 tracelog.go 文件。笔者将 trace ID 视为一组堆栈式的字段,每一级栈能够一层一层地追加 trace ID,从而在不同高度或层面上进行 tracing——这就是在设计理念上与笔者所在团队的实现齐全不同的一个点,这种模式非常适合单体服务,这是另一个大课题了,笔者当前再讲哈。

至于如何将自定义的 trace ID 增加到日志器中,请读者参考笔者的 cloneCtxAndGenerateLog() 函数即可。从这个函数中能够看到,每当增加一个 tracing 字段的时候,tRPC 会新建一个 logger。这也是笔者认为不太得当的一点:这个模式太重了。然而框架如此,也没方法。

server filter

tracelog 的 filter 代码请参见 filter.go。让咱们先来看一下 server filter,该 filter 的性能有两个:

  1. 如果有的话,从 metadata 中提取出 trace ID;如果没有的话,用雪花算法生成一个并存入 ctx 中
  2. 在日志中打印出 server 端执行状况,包含入参、header、metadata、响应、谬误等信息。

其中 1,调用的是前文提到的 Msg 类型的 ServerMetaData 来取得 metadata。

至于 2,请读者理论看 函数实现 更加直观。

client filter

client 实现的逻辑其实也跟 server 侧相似:

  1. 如果有 trace ID,则放入 metadata
  2. 在日志中打印出 client 端执行状况,包含入参、header、metadata、响应、谬误等信息。

应用

咱们参照前文的阐明,在 配置 中加上 tracelog filter 以及日志相干配置。后面咱们提到的 http-auth-server 和 user 两个服务都配置上。而后,依照之前咱们提到的办法启动两个服务。

而后咱们发送命令: curl '127.0.0.1:8001/demo/auth/Login?username=amc'

因为没有指定明码,所以咱们还是失常取得谬误响应: {"err_code":404,"err_msg":"明码谬误"}

谬误不重要,本文咱们要看的是日志。咱们来看看在这个配置下主动生成的日志文件: log/trpc.log。咱们看 http-auth-server 的日志文件。能够看到,文件的每一行就是一个 JSON 数据。咱们取方才的申请产生的日志来看:

{"level":"INFO","time":"2024-03-04 02:19:28","caller":"server/service.go:167","message":"process:1016, http service:demo.httpauth.Auth launch success, tcp:127.0.0.1:8001, serving ..."}
{"level":"DEBUG","time":"2024-03-04 02:19:32","caller":"tracelog/filter.go:107","message":"{\"callee\":\"unknown\",\"http_req\":&{GET /demo/auth/Login?username=amc HTTP/1.1 1 1 map[Accept:[*/*] User-Agent:[curl/7.68.0]] {} <nil> 0 [] false 127.0.0.1:8001 map[] map[] <nil> map[] 127.0.0.1:39774 /demo/auth/Login?username=amc <nil> <nil> <nil> 0xc000279b00 <nil> [] map[]},\"server_metadata\":{\"trace_id_stack\":\"WyJjYXN5cDdwOXpiNCJd\"},\"req\":{\"username\":\"amc\"},\"req_type\":\"github.com/Andrew-M-C/trpc-go-demo/proto/user.*GetAccountByUserNameRequest\",\"rsp\":{\"err_msg\":\"success\",\"user_id\":\"1\",\"username\":\"amc\",\"password_hash\":\"8d969eef6ecad3c29a3a629280e686cf0c3f5d5a86aff3ca12020c923adc6c92\"},\"rsp_type\":\"github.com/Andrew-M-C/trpc-go-demo/proto/user.*GetAccountByUserNameResponse\",\"cost\":\"303.230671ms\"}","trace_id":"casyp7p9zb4"}
{"level":"DEBUG","time":"2024-03-04 02:19:32","caller":"service/http_auth_service.go:50","message":"申请的明码为: , 理论明码为 8d969eef6ecad3c29a3a629280e686cf0c3f5d5a86aff3ca12020c923adc6c92","trace_id":"casyp7p9zb4"}
{"level":"DEBUG","time":"2024-03-04 02:19:32","caller":"tracelog/filter.go:63","message":"{\"caller\":\"unknown\",\"http_req\":&{GET /demo/auth/Login?username=amc HTTP/1.1 1 1 map[Accept:[*/*] User-Agent:[curl/7.68.0]] {} <nil> 0 [] false 127.0.0.1:8001 map[] map[] <nil> map[] 127.0.0.1:39774 /demo/auth/Login?username=amc <nil> <nil> <nil> 0xc000279b00 <nil> [] map[]},\"server_metadata\":null,\"req\":{\"username\":\"amc\"},\"req_type\":\"github.com/Andrew-M-C/trpc-go-demo/proto/httpauth.*LoginRequest\",\"rsp\":{\"err_code\":404,\"err_msg\":\" 明码谬误 \"},\"rsp_type\":\"github.com/Andrew-M-C/trpc-go-demo/proto/httpauth.*LoginResponse\",\"cost\":\"303.953412ms\"}","trace_id":"casyp7p9zb4"}

呃,太长了……取一条短的吧:

{"level":"DEBUG","time":"2024-03-04 02:19:32","caller":"service/http_auth_service.go:50","message":"申请的明码为: , 理论明码为 8d969eef6ecad3c29a3a629280e686cf0c3f5d5a86aff3ca12020c923adc6c92","trace_id":"casyp7p9zb4"}

能够清晰地看到,这一行日志输入了级别、工夫、日志调用方信息、日志注释。此外,还有一个名为 trace_id 的字段,这就是 tracelog 主动生成并插入的成果。


下一步

本文相比后面的文章而言杂了很多,次要是波及的内容互相强耦合,所以我把他们都放在同一篇文章里。举荐读者还是尽量入手试验把这些性能跑一遍,可能在理论开发中更好地了解 tPPC 的这些 feature,这是本人开发 filter 的重要基础知识。

下一篇文章咱们来学习一下 tRPC 的名字服务、服务发现和寻址相干的性能吧。笔者还是会尽量把这系列坚持下去的💪


参考浏览

  • gin 中间件
  • gRPC(Go) 教程 (五)— 拦截器 Interceptor
  • GRPC 的 metadata 应用

本文章采纳 常识共享署名 - 非商业性应用 - 雷同形式共享 4.0 国内许可协定 进行许可。

原作者:amc,原文公布于腾讯云开发者社区,也是自己的博客。欢送转载,但请注明出处。

原文题目:《腾讯 tRPC-Go 教学——(5)filter、context 和日志组件》

公布日期:2024-03-04

原文链接:https://cloud.tencent.com/developer/article/2393468。

退出移动版