Golang装饰器统计函数执行时间方法

本文深入探讨了如何在Go语言中通过高阶函数优雅、安全地模拟装饰器模式来统计函数执行时间，强调必须严格保持原函数签名、使用time.Since()进行稳定计时、在defer中结合recover确保panic场景下耗时仍能准确记录，并采用并发安全的日志方案（如slog或zap）避免输出混乱；它超越了简单的代码技巧，直击高并发、异常处理与可观测性协同落地的核心挑战——让每一毫秒的统计都真实可信、可追溯、不干扰业务。

Go 里没有原生装饰器，用高阶函数模拟最直接

Go 不支持 Python 那种 @decorator 语法，但你可以用「返回函数的函数」来等效实现：把目标函数传进去，返回一个带统计逻辑的新函数。这不是语法糖，而是明确的值传递——func(fn func()) func() 这类签名就是关键。

常见错误是试图在装饰器内部修改原函数签名，比如强行加 context.Context 参数；这会破坏调用方契约。正确做法是保持入参出参完全一致，只在调用前后插逻辑。

• 装饰器本身不关心业务逻辑，只负责计时和日志输出
• 必须用 defer 包裹结束时间采集，否则 panic 时统计会丢失
• 别在装饰器里做阻塞操作（如写文件），否则拖慢所有被装饰函数

time.Since() 是最安全的计时方式，别用 time.Now().Sub()

用 time.Now() 记起点、再用 time.Now().Sub(start) 算耗时，看似合理，但存在竞态风险：如果中间触发 GC 或调度延迟，第二次 time.Now() 可能被显著推迟，导致统计虚高。而 time.Since(start) 底层做了优化，更稳定。

示例中常看到用 time.Now().UnixNano() 手动减法，这不仅冗余，还容易溢出或精度丢失。Go 标准库的 time.Duration 类型就是为此设计的。

• time.Since(start) 返回 time.Duration，可直接格式化为 .String() 或转毫秒 .Milliseconds()
• 如果要打点到监控系统，建议统一转成 float64 毫秒，避免整数截断
• 注意 time.Since() 在纳秒级精度下可能受系统时钟调整影响，生产环境够用，压测场景需配合 runtime.LockOSThread() 控制调度

panic 场景下计时器必须 recover，否则日志永远不输出

装饰器包装后的函数一旦 panic，控制权就跳出当前栈，如果没显式 recover()，计时结束逻辑根本不会执行，你看到的只有 panic 错误，没有耗时数据。

这不是可选项——只要统计目标函数的“完整生命周期”，就必须在 defer 中做 recover，并在 recover 后补上耗时打印。否则你以为函数执行了 200ms，其实它在 5ms 就 panic 了，只是你没看见。

• recover 要放在 defer 内部，且必须在计时结束之后（即先记录耗时，再判断是否 panic）
• recover 到的 err 建议原样 panic(err) 继续向上抛，不要吞掉
• 如果需要区分 panic 和正常返回，可在日志里加字段，比如 status: "panic"

goroutine 多路复用下，log 输出容易乱序或丢日志

高频调用装饰器函数时（比如 HTTP handler），多个 goroutine 并发写日志，若直接用 fmt.Printf 或 log.Print，会出现输出混杂、换行错位，甚至因缓冲区满而丢日志。

这不是装饰器逻辑的问题，而是 I/O 共享资源的竞争。简单加锁成本高，更务实的做法是复用已有日志器（如 zap 或 log/slog），它们默认支持并发安全写入。

• 避免在装饰器里用 fmt.Println，改用 slog.Info 或 logger.Info
• 如果必须用标准库 log，至少用 log.SetFlags(0) 去掉时间戳，减少干扰
• 别把耗时日志和业务日志混在同一输出通道，否则排查慢请求时会被淹没

真正难的不是写个计时装饰器，而是让它的输出在高并发、panic、跨包调用这些边界条件下依然可信。每次加新装饰器前，先想清楚：它会不会掩盖 panic？会不会拖慢关键路径？日志能不能对得上 trace ID？

文中关于的知识介绍，希望对你的学习有所帮助！若是受益匪浅，那就动动鼠标收藏这篇《Golang装饰器统计函数执行时间方法》文章吧，也可关注golang学习网公众号了解相关技术文章。