文章目录

• 前言
• 起因：日志告警引发的思考
• 什么是context
• context的作用
• context超时之后
• • 继续执行 or 中断
  • 最后

    前言

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

    起因：日志告警引发的思考

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

    什么是context

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

    context的作用

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

    可以说，我们的服务里，随处可见携带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

    回到文章最开始提到的线上超时告警频发的问题，经过排查我们发现，一波超时告警的出现实际上只是几条请求引起的（都是同一个trace_id）。究其原因，是我们下游的服务在单次业务请求中，会与很多第三方接口发生交互（在本篇文章的case是并发调用redis），而在业务执行到并发调用redis之前，业务逻辑就已经发生了超时。

    超时后，上游调用端不再继续等待响应，直接返回了超时异常。

    前面已经提到过，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()
    }
    ...
    

    继续执行 or 中断

    知道了问题，其实处理起来就比较容易了，我们将context的状态的判断改写到了合适的位置（在一些耗时的节点之间判断了context的状态，如果判断超时，则直接结束后续的业务流程）

    日志告警清净了！

    但是，这样的处理方式具有普适性吗？可以思考一下，在某些超时的情况中，即便上游已经返回了超时异常，我们仍然希望下游能够将这次业务完整的执行完。

    举一个例子，下游在执行完返回之前，会将本次执行的结果进行缓存。而上游在调用下游之前，也会去取缓存，取到了就直接返回（假设上下游服务共用一套缓存集群）。假如某些请求耗时比较久，而且我们在判断请求超时之后直接中断下游任务的执行，那么，缓存将永远不会生成，上游后续的调用依旧会超时。这种情况下，即便是超时了，我们也希望下游任务能够完整执行，并生成缓存，后续上游就可以直接拿到业务结果返回，避免大量耗时的调用。

    最后

    本篇描述的本身是一个极为常见的问题及处理方案。但是在平时处理问题的过程中，如果勤加思考，仍然会有所收获和提升。

    提个题外话，现在是2023年5月21日，今年（或许从去年开始）的形势确实不太好。小伙伴们或多或少能够感受到就业形势的严峻（有前同事因各种各样的原因10个月没有找到新工作）。越是这样的情况下，越是要好好打磨，提升自己，以应对未来的艰难险阻；

    共勉之～