An implementation detail of the Golang function execution time statistics decorator

background

Recently, I was putting up a new project. In the production environment, in order to monitor the running state of the program in real time, the statistics of the logical execution time is necessary. The expectation of time statistics is as follows:

Implementation details to be stripped out: Time statistics implementation details are not expected to be explicitly written in the main logic. Because other logic and time statistics in the primary logic do not have the same level of abstraction Code for time statistics is reusable The statistical results of the time can be processed. Concurrent programming friendly

Implementation approach

Statistical details are stripped out

The simplest realization of time statistics might look something like this:

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

Clean Code tells us that all function calls within a function should be at the same level of abstraction.

Here the acquisition of the beginning and end of time, the use of the difference of time, belongs to the details of time statistics, first it is not a necessary step of the main process, second they use the functions time.Now () and logicStepOne, logicStepTwo is not at the same level of abstraction.

Therefore, it is better to put the time statistics on top of the f function, such as:

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

The time statistics code is reusable & Statistical results can be processed & It doesn't affect how the function is used

We've achieved the same level of abstraction within the function, but you can certainly tell that the function doesn't work well.

The reason is that we've written f, the function we're calling, dead in the doFWithTimeRecord function. This means that for every function that counts time, I need to implement 1 doXXWithTimeRecord, and the logic in these functions is the same, which violates our DRY (Don 't Repeat Yourself) principle. Therefore, in order to achieve logical reuse, I think decorators are a better implementation: the function to be executed is passed into the time statistics function as a parameter.

Let me give you an example that I saw online

To implement a function, the first reaction must be to find out if the same industry has a ready set of wheels. But let's take a look. I didn't live up to my expectations. Here's an example:

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)
 }
}

What's bad about this code:

This decorator parameter writes the type of the dead function:

type SumFunc func(int64, int64) int64

In other words, as long as I change one function, this decorator won't work, which is not consistent with our second requirement

The time statistic is printed directly to standard output, which means that the result cannot be used by the caller of the original function: only the caller knows that the result is not as expected, that it is taking too long, or that it is normal. This does not meet our third requirement.

How to solve these two problems?

At this point, Refactoring, Improving the Design of existing code tells us: Replace Method with Method Obejct -- replace functions with function objects. What he means is that when a function has more complex temporary variables, we can consider encapsulating the function as a class. So our function takes 1 into 0 arguments. (Of course, as a method in struct, it would be better to make appropriate adjustments)

Now, our code looks like this:

type TimeRecorder interface {
 SetCost(time.Duration)
 TimeCost() time.Duration
}

func TimeCostDecorator(rec TimeRecorder, f func()) func() {
 return func() {
  startTime := time.Now()
  f()
  endTime := time.Now()
  timeCost := endTime.Sub(startTime)
  rec.SetCost(timeCost)
 }
}

Here, the input is written as 1 interface to allow various function objects to enter. You only need to implement the SetCost and TimeCost methods

Concurrent programming friendly

The last thing to consider is that many times a class is a singleton throughout the life of the program, so when it comes to SetCost, you need to consider concurrency. Consider the following solutions:

The time statistics storage object with the decorator is implemented as follows:

func NewTimeRecorder() TimeRecorder {
 return &timeRecorder{}
}

type timeRecorder struct {
 cost time.Duration
}

func (tr *timeRecorder) SetCost(cost time.Duration) {
 tr.cost = cost
}

func (tr *timeRecorder) Cost() time.Duration {
 return tr.cost
}

Extract the function object that can be destroyed after the execution of the essence, new 1 is used every time

The function object implements a locking mechanism for the SetCost function

The three schemes are ranked from the highest to the lowest in the recommended index, because I personally believe that objects should be kept immutable as long as resources allow. At the same time, how to count and store the usage time is actually the matter of the statistical time module itself.

Unit testing

Finally, make up the unit test:

func TestTimeCostDecorator(t *testing.T) {
 testFunc := func() {
  time.Sleep(time.Duration(1) * time.Second)
 }
 
 type args struct {
  rec TimeRecorder
  f func()
 }
 
 tests := []struct {
  name string
  args args
 }{
  {
   "test time cost decorator",
   args{
    NewTimeRecorder(),
    testFunc,
   },
  },
 }
 for _, tt := range tests {
  t.Run(tt.name, func(t *testing.T) {
   got := TimeCostDecorator(tt.args.rec, tt.args.f)
   got()
   if tt.args.rec.Cost().Round(time.Second) != time.Duration(1) * time.Second.Round(time.Second) {
    "Record time cost abnormal, recorded cost: %s, real cost: %s",
    tt.args.rec.Cost().String(),
    tt.Duration(1) * time.Second,
   }
  }) 
 }
}

The test passed, and it proved that the time statistics were ok. This completes the time statistics decorator. If there are any problems with this implementation, or if you have a better implementation, you are welcome to criticize and point out ~