golang에는 defer라는 예약어가 있습니다. defer로 지정된 함수 호출은, defer를 호출한 함수의 종료시에 호출되도록 보장한다는 것입니다. 이를 응용해서 함수의 실행 시간을 측정할 수 있는 범용성 있는 함수를 다음 코드처럼 만들 수 있습니다.
func ElapsedTime(tag string, msg string) func() {
if msg != "" {
log.Printf("[%s] %s", tag, msg)
}
start := time.Now()
return func() { log.Printf("[%s] Elipsed Time: %s", tag, time.Since(start)) }
}
ElapsedTime 함수는 defer 문과 함께 사용되어야 의미가 있는데요. 이 함수를 호출하면 함수를 반환하게 되는데, 이 반환된 함수가 바로 defer 문을 통해 최종적으로 호출될 함수입니다. 이 함수를 테스트하기 위해 아래처럼 코드를 작성해 보겠습니다.
package main
import (
"log"
"time"
)
func bigSlowOperation() int {
defer ElapsedTime("bigSlowOperation", "start")()
time.Sleep(10 * time.Second) // 10초 정도 소요되는 연산에 해당하는 코드라 가정
return 0
}
func ElapsedTime(tag string, msg string) func() {
// 생략
}
func main() {
bigSlowOperation()
}
크고 느린 연산를 호출하는 함수인 bigSlowOperation 함수 내부를 보면 defer 문으로 ElapsedTime 함수를 호출하여 반환된 함수를 호출하고 있습니다. 이를 통해 bigSlowOperation 호출이 끝나면 bigSlowOperation의 실행에 소요된 시간을 표시하게 되는데요. 그 결과는 아래와 같습니다.
2016/10/01 22:28:07 [bigSlowOperation] start 2016/10/01 22:28:17 [bigSlowOperation] Elipsed Time: 10.0007115s