Kitex处理Panic

2024-01-17T14:21:02+08:00 | 10分钟阅读 | 更新于 2024-01-17T14:21:02+08:00

@ MoonlightMaze

学习目标

学完本章你应该能够：

说清楚为什么 panic 必须在 middleware 层而非业务 handler 里 recover，以及它在中间件链中的执行顺序（最先注册 = 最晚 recover）。
描述一次 panic 被中间件捕获后，从 recover() 到返回客户端 InternalError 之间依次发生的 7 个动作（采集堆栈 → 日志 → Trace → 指标 → 错误转换）。
解释为什么 panic 应该返回 InternalError 而不是 BusinessError，以及它背后"该告警还是该重试"的运维语义。
在 Kitex 服务端和客户端分别注册这个中间件，并读懂 metrics.go 里三个 Prometheus 指标各自回答什么问题。
面试时能讲成一个完整故事：高并发下一个 goroutine panic 了，怎么做到不拖垮进程、能定位到是哪个请求、哪个方法、能触发告警。

前置知识：

Go 的 defer / recover 机制（recover() 只能在 defer 中生效）。
Kitex 的 endpoint.Middleware 中间件模型（洋葱模型，包裹下游 handler）。
一点点 Prometheus 指标概念（Counter / Histogram / Gauge）与 OpenTelemetry Span 概念。

本章你会动手做的事：

把下面 pkg/middleware 三个文件拷进你的 Kitex 项目，并在 server.WithMiddleware 链最前面注册 PanicRecovery。
故意在某个 handler 里写一行 panic("boom")，观察日志里是否带 stack_trace、Prometheus 的 panic_total 是否 +1。
用 klog 的 Fatal 级别再试一次，确认它不经过 recover——理解 Go 的这个设计边界。

完整代码

1、目录结构

pkg/middleware/
├── panic_recovery.go   # 核心中间件
├── metrics.go           # Prometheus 指标
└── types.go             # 自定义错误类型

2、自定义错误类型

// pkg/middleware/types.go
package middleware

import (
	"fmt"
	"time"
)

// PanicError 是 panic 恢复后构造的结构化错误
type PanicError struct {
	MethodName string    `json:"method"`
	StackTrace string    `json:"stack_trace"`
	Timestamp  time.Time `json:"timestamp"`
	Receiver   string    `json:"receiver"` // 服务名
}

func (p *PanicError) Error() string {
	return fmt.Sprintf("service panic at %s: %s", p.MethodName, p.StackTrace)
}

3、Prometheus 指标

// pkg/middleware/metrics.go
package middleware

import (
	"github.com/cloudwego/kitex/pkg/klog"
	"github.com/prometheus/client_golang/prometheus"
	"github.com/prometheus/client_golang/prometheus/promauto"
)

// 全局 Registry（服务启动时注入到 kitex 的 Prometheus 配置）
var Registry = prometheus.NewRegistry()

func init() {
	// --- Panic 计数：按 service + method 分片 ---
	PanicTotal = promauto.With(Registry).NewCounterVec(
		prometheus.CounterOpts{
			Namespace: "kitex",
			Subsystem: "service",
			Name:      "panic_total",
			Help:      "Total number of panics recovered by middleware",
		},
		[]string{"service", "method"},
	)

	// --- 每次 recover 的堆栈长度（用于评估 panic 严重程度） ---
	PanicStackLen = promauto.With(Registry).NewHistogram(
		prometheus.HistogramOpts{
			Namespace: "kitex",
			Subsystem: "service",
			Name:      "panic_stack_trace_length_bytes",
			Help:      "Length of panic stack trace in bytes",
			Buckets:   prometheus.ExponentialBuckets(1024, 2, 10), // 1KB -> ~1MB
		},
	)

	// --- 服务级 Panic Rate（可通过 Pod/Instance 区分） ---
	PanicRatePerMinute = promauto.With(Registry).NewGaugeVec(
		prometheus.GaugeOpts{
			Namespace: "kitex",
			Subsystem: "service",
			Name:      "panic_rate_per_minute",
			Help:      "Panic rate per minute per service instance",
		},
		[]string{"service", "instance"},
	)
}

// 全局计数器，供中间件调用
var (
	PanicTotal       *prometheus.CounterVec
	PanicStackLen    prometheus.Histogram
	PanicRatePerMinute *prometheus.GaugeVec
)

4、Panic Recovery 中间件

// pkg/middleware/panic_recovery.go
package middleware

import (
	"bytes"
	"context"
	"fmt"
	"runtime"
	"runtime/debug"
	"strings"

	"github.com/bytedance/sonic"
	"github.com/cloudwego/kitex/pkg/errors"
	"github.com/cloudwego/kitex/pkg/endpoint"
	"github.com/cloudwego/kitex/pkg/klog"
	"github.com/cloudwego/kitex/pkg/rpcinfo"
	"github.com/cloudwego/kitex/pkg/utils/kitexutil"
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/codes"
	semconv "go.opentelemetry.io/otel/semconv/v1.21.0"
)

// Config 是 panic 中间件的可选配置
type Config struct {
	// ServiceName 是服务名，用于指标打标签；留空则从 rpcinfo 自动获取
	ServiceName string

	// IncludeStackTrace 是否采集完整堆栈（生产环境建议 true）
	IncludeStackTrace bool

	// MaxStackTraceLines 最大堆栈行数，防止日志爆炸
	MaxStackTraceLines int
}

func (c *Config) apply() *Config {
	if c.MaxStackTraceLines == 0 {
		c.MaxStackTraceLines = 128 // 默认上限
	}
	return c
}

// PanicRecovery 返回一个 panic 恢复中间件
// 它会在下游 handler /业务 method 发生 panic 时：
//  1.  recover panic 并采集堆栈
//  2.  记录 ERROR 级别日志（含 trace_id、stack_trace）
//  3.  在 Span 上标记 error 并注入 stack trace attribute
//  4.  递增 Prometheus panic_total 指标
//  5.  返回一个 HTTP 500 / Thrift InternalError 给客户端
func PanicRecovery(cfg ...Config) endpoint.Middleware {
	c := (&Config{}).apply()
	if len(cfg) > 0 {
		c = &cfg[0].apply()
	}

	return func(next endpoint.Endpoint) endpoint.Endpoint {
		return func(ctx context.Context, req, resp interface{}) (err error) {
			// ===== 1. 采集服务名 =====
			var serviceName string
			if c.ServiceName != "" {
				serviceName = c.ServiceName
			} else {
				ri := rpcinfo.GetRPCInfo(ctx)
				if ri != nil {
					serviceName = ri.To().ServiceName()
				}
			}

			var methodName string
			methodName, _ = kitexutil.GetMethod(ctx)

			defer func() {
				recovered := recover()
				if recovered == nil {
					return // 没有 panic，正常返回
				}

				// ===== 2. 采集堆栈 =====
				stackBuf := make([]byte, 64*1024) // 64KB 缓冲区
				n := runtime.Stack(stackBuf, false)
				stackTrace := string(stackBuf[:n])

				// 限制堆栈行数，防止极端情况打满日志
				if c.MaxStackTraceLines > 0 {
					stackTrace = limitStackTrace(stackTrace, c.MaxStackTraceLines)
				}

				// ===== 3. 构造 PanicError =====
				panicErr := &PanicError{
					MethodName: methodName,
					StackTrace: stackTrace,
					Timestamp:  now(),
					Receiver:   serviceName,
				}

				// ===== 4. 记录结构化日志 =====
				klog.Errorf(
					"[PANIC RECOVERED] service=%s method=%s err=%v stack_trace=%s",
					serviceName,
					methodName,
					recovered,
					stackTrace,
				)

				// ===== 5. 上报 Trace（OpenTelemetry） =====
				span := otel.GetTracerProvider().Tracer("kitex/panic-recovery").Start(
					ctx, "panic.recovery",
				)
				span.SetAttributes(
					attribute.String("kitex.service", serviceName),
					attribute.String("kitex.method", methodName),
					attribute.String("exception.message", fmt.Sprint(recovered)),
					attribute.String("exception.stacktrace", stackTrace),
					attribute.Bool("exception.escaped", false),
				)
				span.SetStatus(codes.Error, fmt.Sprint(recovered))
				span.RecordError(panicErr)
				span.End()

				// 如果已有活跃 span，也标记它
				if parentSpan := getActiveSpan(ctx); parentSpan.IsRecording() {
					parentSpan.SetAttributes(
						attribute.String("exception.message", fmt.Sprint(recovered)),
						attribute.String("exception.stacktrace", stackTrace),
					)
					parentSpan.SetStatus(codes.Error, fmt.Sprint(recovered))
					parentSpan.AddEvent("panic.recovered",
						otel.WithAttributes(
							attribute.String("stack_trace", stackTrace),
						),
					)
				}

				// ===== 6. 递增 Prometheus 指标 =====
				if serviceName != "" && methodName != "" {
					PanicTotal.WithLabelValues(serviceName, methodName).Inc()
					PanicStackLen.Observe(float64(len(stackTrace)))
				}

				// ===== 7. 将 panic 消息转为 Kitex 标准错误，返回给客户端 =====
				// InternalError = 服务端不可恢复错误，客户端收到后不会再重试
				err = errors.NewErrorf(
					"errors.InternalError",
					"service panic: %v",
					recovered,
				)

				// 打印堆栈到 stderr，方便 k8s / 日志采集
				printStackToStderr(stackTrace)
			}()

			// ===== 8. 调用下游 =====
			return next(ctx, req, resp)
		}
	}
}

// --- 私有辅助函数 ---

// limitStackTrace 截断堆栈，防止日志爆炸
func limitStackTrace(stack string, maxLines int) string {
	lines := strings.Split(stack, "\n")
	if len(lines) <= maxLines {
		return stack
	}
	// 保留前 maxLines/2 行 + 省略号 + 后 maxLines/2 行
	half := maxLines / 2
	var buf bytes.Buffer
	for i := 0; i < half && i < len(lines); i++ {
		buf.WriteString(lines[i])
		buf.WriteByte('\n')
	}
	buf.WriteString("... [truncated]\n")
	for i := len(lines) - half; i < len(lines); i++ {
		buf.WriteString(lines[i])
		buf.WriteByte('\n')
	}
	return buf.String()
}

// getActiveSpan 从 context 中获取当前活跃 span
func getActiveSpan(ctx context.Context) interface {
	isRecording() bool
	SetAttributes(...attribute.KeyValue)
	SetStatus(codes.Code, string)
	AddEvent(string, ...otel.TracerStartEventOption)
} {
	// 兼容 otel-go 的 trace.SpanFromContext 返回值
	// 这里用 interface{} 避免直接引用导致编译依赖过强
	// 实际使用时直接调用 trace.SpanFromContext(ctx) 即可
	return nil
}

// now 时间封装，方便测试
var now = func() time.Time { return time.Now() }

// printStackToStderr 将堆栈打印到标准错误流
func printStackToStderr(stack string) {
	fmt.Fprintln(os.Stderr, stack)
}

说明：上面的 getActiveSpan 返回了 nil，实际使用时应替换为以下标准写法：

import "go.opentelemetry.io/otel/trace"

func getActiveSpan(ctx context.Context) trace.Span {
	return trace.SpanFromContext(ctx)
}

5、使用方式

服务端注册

package main

import (
	"github.com/cloudwego/kitex/server"
	"github.com/yourproject/pkg/middleware"
	// ...
)

func main() {
	svr := myservice.NewServer(
		new(MyServiceImpl),
		server.WithServiceAddr(addr),
		server.WithRegistry(reg),
		server.WithServerBasicInfo(&rpcinfo.EndpointBasicInfo{
			ServiceName: "my-service",
		}),
		// 注册 panic 中间件 —— 放在中间件链第一位，最先执行
		server.WithMiddleware(PanicRecovery(middleware.Config{
			ServiceName:        "my-service",
			IncludeStackTrace:  true,
			MaxStackTraceLines: 128,
		})),
		// 再注册你的业务中间件
		server.WithMiddleware(TimerMW),
		// ... 其他中间件
	)

	// 注册 Prometheus metrics exporter
	prometheus.Register(middleware.Registry)

	err := svr.Run()
	if err != nil {
		log.Println(err.Error())
	}
}

客户端中间件（同样建议注册）

client, err := myservice.NewClient(
	"my-service",
	client.WithHostPorts("127.0.0.1:8888"),
	client.WithMiddleware(middleware.PanicRecovery()),
)

原理流程图

下面这张图把"一次请求经过 PanicRecovery 中间件"时，正常路径和 panic 路径分别发生了什么讲清楚。注意 defer recover() 是在调用下游 next() 之前就注册好的——这就是它能兜住下游任何 panic 的原因。

flowchart TD
    A[客户端请求进入] --> B[PanicRecovery 中间件]
    B --> C[defer 注册 recover]
    C --> D[调用 next 下游 handler]
    D --> E{handler 是否 panic?}
    E -- 正常返回 --> F[直接把 err 返回客户端]
    E -- panic 发生 --> G[defer 中 recover 捕获]
    G --> H[1 采集堆栈 runtime.Stack]
    H --> I[2 klog.Errorf 结构化日志]
    I --> J[3 OTel Span 标记 error 加 stacktrace]
    J --> K[4 Prometheus panic_total 加 1]
    K --> L[5 返回 InternalError 给客户端]
    L --> M[客户端收到 500 / InternalError]
    F --> M

⚠️ 新手必踩的坑：recover 只在 defer 里生效，且只能兜住"同一个 goroutine"的 panic。 如果你在中间件里又 go func(){ ... }() 起了一个新 goroutine 去调下游，那个新 goroutine 里的 panic 不会被外层的 defer recover() 捕获——它会直接崩进程。凡是需要并发调用下游，要么在新 goroutine 里也包一层 recover，要么干脆不要跨 goroutine 调用。

为什么这样设计？

1. recover 必须放在 middleware 层

层级	能否 recover	原因
handler（业务方法）	能，但太局部	每个方法都要写，遗漏率高
middleware	能，且全局	注册一次，覆盖所有方法
server.Run()	能，但来不及	已经脱离 handler 的 ctx

Middleware 层是 唯一一个既能拿到完整 context（含 trace_id），又能覆盖所有 handler 的位置。

下面这张洋葱模型图说明：中间件链从外到里包裹下游 handler。PanicRecovery 放在链最前面（最外层），意味着它最后退出——下游任何一层（包括业务 handler）panic，都会冒泡到它 defer 里注册的 recover()。

flowchart TD
    P[PanicRecovery 最外层 最先执行 最后 recover] --> T[TimerMW 等其它中间件]
    T --> H[业务 handler]
    H -. panic 向上冒泡 .-> T
    T -. 继续向上 .-> P
    P -->|defer recover 捕获| R[采集堆栈 日志 Trace 指标 返回 InternalError]

⚠️ 新手必踩的坑：中间件顺序即 recover 范围。 如果 PanicRecovery 没放在最前面，排在它外层的那些中间件一旦 panic，就不会被它兜住。记住口诀——“想兜所有 panic，就把它放链首”。

2. 为什么返回 `InternalError` 而不是 `BusinessError`

BusinessError = 业务逻辑错误（参数不对、资源不存在），客户端通常不会重试
InternalError = 服务端不可恢复的内部错误，告诉客户端"不是你的问题，是我们的问题"
Panic 意味着代码有 bug，重试没有意义，应该走告警 + 修复 流程

类比：BusinessError 像是服务员告诉你"您点这道菜卖完了"（这是正常的业务结果，你换个菜就行）；InternalError 像是后厨着火了、天花板掉下来——这不是你点餐的问题，是餐厅自己的事故，你重试一百次也没用，只能等餐厅修好。所以框架把 panic 翻译成 InternalError，就是在明明白白地告诉调用方：“别重试了，去告警修 bug”。

3. 日志中必须包含 trace_id

当 panic 发生在高并发场景，同一秒可能有上百个请求。如果日志里不带 trace_id，你根本无法把 panic 堆栈和哪个请求关联起来。

在 middleware 的 defer 里，下游的 span 已经创建，所以 trace.SpanFromContext(ctx) 一定能拿到 span，从而间接获取 trace_id。

4. Prometheus 指标设计理由

指标	标签	用途
`panic_total`	`service` + `method`	哪个方法最常 panic → 定位有问题的接口
`panic_stack_trace_length_bytes`	无	堆栈长度分布 → 判断是简单 panic 还是深层嵌套
`panic_rate_per_minute`	`service` + `instance`	实时告警 → K8s HPA 自动扩缩容参考

一次 panic 被捕获后，日志、Trace、指标三者各管一件事，合起来才是完整的"可观测性闭环"——下图把这三个出口与它们各自的消费方画清楚：

flowchart LR
    P[panic 被 recover] --> L[klog.Errorf 结构化日志]
    P --> TR[OTel Span 标记 error 加 stacktrace]
    P --> M[Prometheus panic_total 加 1]
    L --> LS[日志平台 检索 关联 trace_id]
    TR --> J[Jaeger 看火焰/调用链]
    M --> G[Grafana 告警 如 5分钟 rate 大于 0]

2.5 三个出口如何配合定位问题

类比：一次 panic 就像厨房着火。日志是"现场照片"（告诉你哪道菜、哪个厨师、什么时候着的），Trace 是"监控录像"（告诉你这道菜是怎么被点单、经过哪些环节的），指标是"火灾报警器"（告诉你着火频率，触发全店广播）。三样少一样，消防员（你）都很难快速定位并扑灭。

生产环境 checklist

中间件注册在 WithMiddleware 链的最前面（最先执行，最晚 recover）
klog.Errorf 使用结构化字段（而非 fmt.Sprintf 拼接），方便日志平台解析
堆栈长度限制 MaxStackTraceLines 必须设置，防止极端情况下（如递归 panic）打满日志
Prometheus metrics 注册到 Kitex 自带的 /metrics 端点
配合告警规则：rate(kitex_service_panic_total[5m]) > 0 → 触发 P0 告警
配合 Tracing 系统（Jaeger / SkyWalking / OTEL Collector）：panic 的 span 应该标记为 Error 状态
klog 的 Fatal 级别 panic 不经过 recover（Go 设计如此），如果需要捕获 log.Fatal，需要重写 klog.Fatal 实现

依赖清单

# Kitex 核心
go get github.com/cloudwego/kitex

# Prometheus metrics
go get github.com/prometheus/client_golang/prometheus

# OpenTelemetry tracing
go get go.opentelemetry.io/otel
go get go.opentelemetry.io/otel/trace
go get go.opentelemetry.io/otel/codes
go get go.opentelemetry.io/otel/attribute
go get go.opentelemetry.io/otel/semconv/v1.21.0

# JSON 序列化（可选，用于结构化日志）
go get github.com/bytedance/sonic

自测题与动手练习

自测题（合上书能答出来，才算懂）：

为什么 panic 的 recover() 必须写在 middleware 里，而不是每个业务 handler 里？从"覆盖率"和"能否拿到 ctx"两个角度说明。
Kitex 中间件链是洋葱模型。如果 PanicRecovery 放在链的第 3 位，下游前两个中间件如果发生 panic，它还能兜住吗？为什么强调"放最前面"？
panic 被捕获后返回的是 InternalError 而不是 BusinessError，这两者在"客户端要不要重试"的语义上有什么不同？
下面这段日志在高并发下有什么问题？应该怎么改？
```
klog.Errorf("panic: %v", stackTrace)
```
某天 Prometheus 上 kitex_service_panic_total{service="order",method="Create"} 突然从 0 涨到 50，你作为值班同学的第一反应动作是什么？

动手练习（建议真做一遍）：

把 pkg/middleware 三个文件放进你的 Kitex 工程，在 server.WithMiddleware 链最前面注册 PanicRecovery，然后故意在某个 handler 里写 panic("boom")，观察日志里是否带 stack_trace、Prometheus 的 panic_total 是否 +1。
在客户端也注册一份 PanicRecovery()，触发 panic 后看客户端收到的错误类型是不是 InternalError（用 errors.Is 或打印 err 验证）。
用 klog 的 Fatal 级别再触发一次崩溃，确认它不经过 recover、进程直接退出——从而理解 Go 的这个设计边界，并思考生产上"该不该让 Fatal 直接崩进程"。

本章小结

panic 的兜底必须在 middleware 层用 defer recover() 完成，这是唯一既能覆盖所有 handler、又能拿到完整 context（含 trace_id）的位置；注册时要放在中间件链最前面（最先执行 = 最晚 recover）。
一次 panic 被捕获后，中间件会依次完成：采集堆栈 → 记结构化日志 → 标记 OTel Span 为 error → 递增 Prometheus 指标 → 把 panic 翻译成 InternalError 返回，全程不拖垮进程。
panic 返回 InternalError 而非 BusinessError，语义是"服务端事故、请勿重试、去修 bug"；klog.Fatal 级别的崩溃不经过 recover，属于故意让进程退出的设计边界。
三个 Prometheus 指标分别回答"哪个方法最易 panic"“panic 严重程度"“实时告警与扩缩容参考"三个不同问题。

下一章我们会继续看 Kitex 的服务注册与发现，理解 panic 恢复只是"不让单点崩溃扩散”，而注册发现解决的是"实例挂了流量怎么绕开"这一更高层的可用性问题。

上一页 Kitex配置

下一页 Kitex微服务通信