golang 服务中 context 超时处理的思考

本文介绍: 公司运行的服务代码中，随处可见各种各样的日志信息，其中大多数是用来记录各种异常的日志，一方面，当出现问题时，通过日志我们可以快速的定位引发问题的原因；另外我们可以通过日志平台，对一些错误级别比较高的日志进行监控，从而能够快速响应系统可能会出现的问题。在Go 语言中，Con text是一个非常重要的概念，它存在于一个完整的业务生命周期内，Con textDe ad line()Done()Er r()和Value()。其中，Dead line()方法返回 context的截止日期，Done()方法返回一个只读的。

公司运行的服务代码中，随处可见各种各样的日志信息，其中大多数是用来记录各种异常的日志，一方面，当出现问题时，通过日志我们可以快速的定位引发问题的原因；另外我们可以通过日志平台，对一些错误级别比较高的日志进行监控，从而能够快速响应系统可能会出现的问题。

虽然日志告警很有用，但如果告警次数过于频繁，反而会降低开发人员对于系统异常的敏感度，使得告警变得毫无意义。因此，我们需要对告警进行治理。最近，由于一次治理线上频发的超时告警，使得笔者开始思考起context deadline exceed异常的问题。

在Go 语言中，Context是一个非常重要的概念，它存在于一个完整的业务生命周期内，Context类型是一个接口类型，它定义了四个方法：Deadline()、Done()、Err()和Value()。其中，Deadline()方法返回context的截止日期，Done()方法返回一个只读的channel，当Context被取消或超时时，该channel会被关闭，Err()方法返回Context被取消的原因，Value()方法返回Context中与key相关联的值。

在实际应用中，我们可以使用Context包来传递请求的元数据，例如请求ID、超时信息等等。此外，我们还可以使用 context包来控制goroutine的生命周期（最常见的），例如在HTTP请求处理程序中，我们可以使用 context包来取消正在处理的请求。

可以说，我们的服务里，随处可见携带context参数的方法。

package main

import (
	"context"
	"fmt"
	"time"
)

func timeConsuming(ctx context.Context, costTime int) {

	ctx.Done()

	for i := 1; i <= costTime; i++ {
		// 模拟一些耗时操作
		time.Sleep(1 * time.Second)
		fmt.Printf("协程正在运行第%v次...n", i)
	}
}

func main() {
	// 创建一个父级 context，设置超时时间为 5 秒钟
	parentCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
	defer cancel()

	// 创建一个子级 context，用于控制协程
	childCtx, childCancel := context.WithCancel(parentCtx)
	defer childCancel()

	costTime := 5 // 模拟耗时 5 秒钟

	// 启动一个协程
	go func(ctx context.Context) {
		for {
			select {
			case <-ctx.Done():
				// 如果收到取消信号，退出协程
				fmt.Println("协程退出")
				return
			case <-time.After(15 * time.Second):
				fmt.Println("协程超时")
			default:
				timeConsuming(childCtx, costTime)
			}
		}
	}(childCtx)

	// 等待 3 秒钟，然后取消子级 context
	time.Sleep(3 * time.Second)
	fmt.Println("取消协程")
	childCancel()

	// 继续等待 3 秒钟，模拟主协程的一些其他操作
	time.Sleep(3 * time.Second)
	fmt.Println("主协程退出")
}

协程正在运行第1次...
协程正在运行第2次...
取消协程
协程正在运行第3次...
协程正在运行第4次...
协程正在运行第5次...
协程退出
主协程退出

虽然说Context可以用来管理goroutine，但是可以看到，Context超时之后，goroutine仍然在执行完成之后才会退出，Context无法真正做到强制杀死goroutine

前面已经提到过，goroutine是无法强制杀死的，此时goroutine携带着已经超时的context依旧在执行着业务逻辑，在执行到并发调用 redis时，由于context已经超时，调用无一例外的全部抛出超时错误（实际上并未真正发生调用 redis，redis 客户端代码在调用前判断了context的状态）,
从而导致个位数的超时请求却引起了大量日志的超时告警。

...
//If Done is not yet closed, Err returns nil.
// If Done is closed, Err returns a non-nil error explaining why:
// Canceled if the context was canceled
// or DeadlineExceeded if the context's deadline passed.
// After Err returns a non-nil error, successive calls to Err return the same error.
if ctx.Err() != nil { // 这里抛出了context deadline exceeded 异常
	return nil, ctx.Err()
}
...