The flogger package provides a simple function call logging by wrapping zerolog package.
Simplify a routine of logging function's input parameters and execution duration.
go get -u github.com/axkit/flogger
For simple logging use global variable flogger.G
package main
import (
"github.com/axkit/flogger"
)
func main() {
zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
log.Info().Msg("application started")
task("John", 100, 10)
}
func task(name string, a, b int) {
fc := flogger.G.Enter(name, a, b)
defer fc.Exit()
// function logic
// write intermediate lines to the log
fc.Debug().Int("subtask", 1).Msg("completed")
}
// Output:
{"time":1516134303,"level":"info","message":"application started"}
{"time":1516134304,"level":"debug","func":"task","params":"[John 100 10]","message":"enter"}
{"time":1516134310,"level":"debug","func":"task","subtask":1,"message":"completed"}
{"time":1516134315,"level":"debug","func":"task","dur":500,"message":"exit"}
Let's say we have following structure:
import "github.com/axkit/flogger"
type CustomerRepo struct {
flog flogger.Logger
...
}
func NewCustomerRepo(l *zerolog.Logger) *CustomerRepo {
return &CustomerRepo{
flog: flogger.New(l, "repo", "customer"),
}
}
Writes 1 line: the function invocation fact.
func (repo *CustomerRepo)CustomerByID(id int) *Customer {
repo.flog.Enter()
}
// Output
{"time":1516134304,"level":"debug","func":"CustomerByID","message":"enter"}
Writes 1 line: the function invocation fact with input parameters.
func (repo *CustomerRepo)NewCustomer(id int, name string, age int, ssn string) *Customer {
repo.flog.Enter(id, name, age)
}
// Output
{"time":1516134304,"level":"debug","func":"NewCustomer","params":"[10 John 42]","message":"enter"}
Writes 2 lines: the function invocation fact with input parameters and function execution duration on exit.
func (repo *CustomerRepo)CustomerByID(id int) *Customer {
defer repo.flog.Enter(id).Exit()
}
// Output
{"time":1516134304,"level":"debug","func":"CustomerByID","params":"[10]","message":"enter"}
{"time":1516134310,"level":"debug","func":"CustomerByID","dur":670,"message":"exit"}
Writes 3 lines: the function invocation fact with input parameters. Writes the function execution duration on exit. Writes intermediate line as well.
func (repo *CustomerRepo)CustomerByID(id int) *Customer {
// fc stands for function call
fc := repo.flog.Enter(id)
defer fc.Exit()
fc.Debug().Int("subtask", 1).Msg("completed)
}
Writes 1 line: the function execution duration on exit.
func (repo *CustomerRepo)CustomerByID(id int) *Customer {
defer repo.flog.Enter().Exit()
}
Writes 1 line: the function execution duration and input params on exit.
func (repo *CustomerRepo)CustomerByID(id int) *Customer {
defer repo.flog.EnterSilent().Exit(id)
}
Writes 0 or 1 line: the function execution duration and input params on exit conditionally. Writes nothing if OnExit() was not called.
func (repo *CustomerRepo)CustomerByID(id int) *Customer {
fc := repo.flog.EnterSilent()
defer fc.Exit()
if err := sql.Query(...); err != nil {
fc.OnExit(id)
}
return nil
}
Exit method calls floggger.ExitHandler (declared as public variable) function to write log item on exit. As instance, we need extend exit call and save performance metrics.
flog := flogger.New(l, "repo", "customer")
flog.SetSecondExitHandler(func(fc *flogger.FuncCall){
// call Prometheus
//
})
...
..
// write 1 line to the log on exit together with pushing
// information to Prometeus.
defer flog.EnterSilent().Exit(id, name, age)
cpu: Intel(R) Core(TM) i7-6700HQ CPU @ 2.60GHz
BenchmarkLogger_Enter1-8 714012 1660 ns/op 360 B/op 6 allocs/op
BenchmarkLogger_Enter3-8 557878 2063 ns/op 400 B/op 6 allocs/op
BenchmarkLogger_EnterSilentExit1-8 614272 1995 ns/op 360 B/op 6 allocs/op
BenchmarkLogger_EnterSilentExit3-8 412462 2650 ns/op 400 B/op 6 allocs/op
BenchmarkLogger_EnterExit3-8 477002 2426 ns/op 400 B/op 6 allocs/op
MIT