如何在http.TimeoutHandler取消Context时获取堆栈跟踪用于调试

方法一：通过中间件包装Context监听取消信号 #

可以编写一个通用中间件，给请求上下文添加取消监听，一旦Context被取消（包括TimeoutHandler触发的超时取消），就立即捕获并打印当前堆栈。

中间件实现代码 #

import (
    "context"
    "log"
    "net/http"
    "runtime"
)

func contextCancelLogger(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        // 基于原始请求上下文创建带取消监听的新上下文
        ctx, cancel := context.WithCancel(r.Context())
        defer cancel()

        // 启动goroutine监听取消信号
        go func() {
            select {
            case <-ctx.Done():
                // 捕获当前堆栈并打印
                stackBuf := make([]byte, 8192)
                stackLen := runtime.Stack(stackBuf, false)
                log.Printf("请求上下文被取消，执行堆栈:\n%s", stackBuf[:stackLen])
            }
        }()

        // 将包装后的上下文传入后续处理链
        next.ServeHTTP(w, r.WithContext(ctx))
    })
}

集成到服务器配置 #

修改原有的路由注册逻辑，将中间件添加到处理链中：

mux := http.NewServeMux()
// 给根handler添加取消日志中间件
mux.Handle("/", contextCancelLogger(http.HandlerFunc(handle_root)))

srv := &http.Server{
    Addr:         fmt.Sprintf("%s:%d", args.address, args.port),
    ReadTimeout:  2 * time.Second,
    WriteTimeout: 2 * time.Second,
    IdleTimeout:  2 * time.Second,
    Handler:      http.TimeoutHandler(mux, 1500*time.Millisecond, "Backend timeout exceeded"),
}
log.Fatal(srv.ListenAndServe())

当TimeoutHandler触发超时取消上下文时，goroutine会立即打印当时的执行堆栈，你可以从堆栈中看到代码卡在了哪一步（比如某个QueryContext调用）。

方法二：自定义TimeoutHandler在取消源头打印堆栈 #

如果需要更精准的控制，可以直接实现一个类似原生TimeoutHandler的逻辑，在触发超时取消的代码位置直接打印堆栈。

自定义TimeoutHandler实现 #

import (
    "context"
    "fmt"
    "log"
    "net/http"
    "runtime"
    "time"
)

func CustomTimeoutHandler(h http.Handler, timeout time.Duration, msg string) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        ctx, cancel := context.WithTimeout(r.Context(), timeout)
        defer cancel()

        done := make(chan struct{})
        go func() {
            defer close(done)
            h.ServeHTTP(w, r.WithContext(ctx))
        }()

        select {
        case <-done:
            return
        case <-ctx.Done():
            // 超时触发时直接打印堆栈
            stackBuf := make([]byte, 8192)
            stackLen := runtime.Stack(stackBuf, false)
            log.Printf("超时触发，上下文取消堆栈:\n%s", stackBuf[:stackLen])
            // 返回超时响应
            w.WriteHeader(http.StatusServiceUnavailable)
            fmt.Fprintln(w, msg)
        }
    })
}

替换原生TimeoutHandler #

修改服务器的Handler配置：

srv := &http.Server{
    // ... 其他配置不变
    Handler: CustomTimeoutHandler(mux, 1500*time.Millisecond, "Backend timeout exceeded"),
}

这种方式直接在超时触发的源头捕获堆栈，避免了中间件可能带来的微小延迟，信息也更准确。

额外优化建议 #

• 可以调整stackBuf的大小（比如改为16384），确保能捕获完整的调用堆栈。
• 生产环境中可以添加日志采样逻辑，避免频繁超时导致日志量过大。
• 如果需要关联具体SQL语句，可以在调用QueryContext时，通过context.WithValue将SQL语句存入上下文，取消时一并打印。

内容的提问来源于stack exchange，提问作者maxschlepzig