Golang装饰器模式实现函数执行时间的自动化统计

go中可用高阶函数模拟装饰器,需保持原函数签名一致,用time.since()安全计时,defer中recover确保panic时仍输出耗时,日志应并发安全且与业务分离。

Golang装饰器模式实现函数执行时间的自动化统计

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 类型就是为此设计的。

立即学习go语言免费学习笔记(深入)”;

  • 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.Printflog.Print,会出现输出混杂、换行错位,甚至因缓冲区满而丢日志。

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

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

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