Golang 函数执行时间统计装饰器的一个实现详解

2020-01-28 13:49:43王振洲

背景

最近在搭一个新项目的架子,在生产环境中,为了能实时的监控程序的运行状态,少不了逻辑执行时间长度的统计。时间统计这个功能实现的期望有下面几点:

    实现细节要剥离:时间统计实现的细节不期望在显式的写在主逻辑中。因为主逻辑中的其他逻辑和时间统计的抽象层次不在同一个层级 用于时间统计的代码可复用 统计出来的时间结果是可被处理的。 对并发编程友好

实现思路

统计细节的剥离

最朴素的时间统计的实现,可能是下面这个样子:


func f() {
 startTime := time.Now()
 logicStepOne()
 logicStepTwo()
 endTime := time.Now()
 timeDiff := timeDiff(startTime, endTime)
 log.Info("time diff: %s", timeDiff)
}

《代码整洁之道》告诉我们:一个函数里面的所有函数调用都应该处于同一个抽象层级。

在这里时间开始、结束的获取,使用时间的求差,属于时间统计的细节,首先他不属于主流程必要的一步,其次他们使用的函数 time.Now() 和 logicStepOne, logicStepTwo 并不在同一个抽象层级。

因此比较好的做法应该是把时间统计放在函数 f 的上层,比如:


func doFWithTimeRecord() {
 startTime: = time.Now()
 f()
 endTime := Time.Now()
 timeDiff := timeDIff(startTime, endTime)
 log.Info("time diff: %s", timeDiff)
}

时间统计代码可复用&统计结果可被处理&不影响原函数的使用方式

我们虽然达成了函数内抽象层级相同的目标,但是大家肯定也能感受到:这个函数并不好用。

原因在于,我们把要调用的函数 f 写死在了 doFWithTimeRecord 函数中。这意味着,每一个要统计时间的函数,我都需要实现一个 doXXWithTimeRecord, 而这些函数里面的逻辑是相同的,这就违反了我们 DRY(Don't Repeat Yourself)原则。因此为了实现逻辑的复用,我认为装饰器是比较好的实现方式:将要执行的函数作为参数传入到时间统计函数中。

举个网上看到的例子

实现一个功能,第一反应肯定是查找同行有没有现成的轮子。不过看了下,没有达到自己的期望,举个例子:


type SumFunc func(int64, int64) int64

func timedSumFunc(f SumFunc) SumFunc {
 return func(start, end int64) int64 {
  defer func(t time.Time) {
   fmt.Printf("--- Time Elapsed: %v ---n", time.Since(t))
  }(time.Now())
  
  return f(start, end)
 }
}

说说这段代码不好的地方:

这个装饰器入参写死了函数的类型:


type SumFunc func(int64, int64) int64

也就是说,只要换一个函数,这个装饰器就不能用了,这不符合我们的第2点要求

这里时间统计结果直接打印到了标准输出,也就是说这个结果是不能被原函数的调用方去使用的:因为只有掉用方,才知道这个结果符不符合预期,是花太多时间了,还是正常现象。这不符合我们的第3点要求。