diff --git a/README.md b/README.md index 42f66af..f29abeb 100644 --- a/README.md +++ b/README.md @@ -65,4 +65,17 @@ pkg: kumoly.io/lib/klog cpu: AMD Ryzen 9 5900X 12-Core Processor BenchmarkDefault-12 24697 47673 ns/op 21337 B/op 291 allocs/op BenchmarkSub1-12 22639 52841 ns/op 22103 B/op 351 allocs/op + +v0.0.5 +go test -bench . -run none --benchmem +goos: linux +goarch: amd64 +pkg: kumoly.io/lib/klog +cpu: AMD Ryzen 9 5900X 12-Core Processor +BenchmarkDefault-12 25216 47204 ns/op 20953 B/op 291 allocs/op +BenchmarkSub1-12 22789 52306 ns/op 21719 B/op 351 allocs/op +BenchmarkStackSTD-12 105280 11347 ns/op 3596 B/op 26 allocs/op +BenchmarkStackSTDStr-12 234535 5109 ns/op 2755 B/op 27 allocs/op +BenchmarkStackCust-12 14764 80228 ns/op 171553 B/op 60 allocs/op +BenchmarkStackCustStr-12 15417 78187 ns/op 171262 B/op 61 allocs/op ``` \ No newline at end of file diff --git a/log_test.go b/log_test.go index 12b90ee..2daaa93 100644 --- a/log_test.go +++ b/log_test.go @@ -3,6 +3,7 @@ package klog import ( "io" "os" + "runtime" "testing" ) @@ -182,3 +183,53 @@ func TestIntercept(t *testing.T) { }) l.Info("original") } + +func BenchmarkStackSTD(b *testing.B) { + f := func() []byte { + buf := make([]byte, 1024) + for { + n := runtime.Stack(buf, false) + if n < len(buf) { + return buf[:n] + } + buf = make([]byte, 2*len(buf)) + } + } + LEVEL = 15 + l := Sub("StackSTD") + l.SetErrOutput(io.Discard) + l.SetOutput(io.Discard) + for i := 0; i < b.N; i++ { + l.Info(f()) + } +} + +func BenchmarkStackSTDStr(b *testing.B) { + LEVEL = 15 + l := Sub("StackSTD") + l.SetErrOutput(io.Discard) + l.SetOutput(io.Discard) + for i := 0; i < b.N; i++ { + l.Info(stack()) + } +} + +func BenchmarkStackCust(b *testing.B) { + LEVEL = 15 + l := Sub("StackCust") + l.SetErrOutput(io.Discard) + l.SetOutput(io.Discard) + for i := 0; i < b.N; i++ { + l.Info(Stack(3)) + } +} + +func BenchmarkStackCustStr(b *testing.B) { + LEVEL = 15 + l := Sub("StackCust") + l.SetErrOutput(io.Discard) + l.SetOutput(io.Discard) + for i := 0; i < b.N; i++ { + l.Info(string(Stack(3))) + } +} diff --git a/util.go b/util.go index ea6ecfa..07e28e3 100644 --- a/util.go +++ b/util.go @@ -1,7 +1,9 @@ package klog import ( + "bytes" "fmt" + "io/ioutil" "runtime" ) @@ -38,3 +40,71 @@ func getAllOffsprings(l *Logger) []*Logger { } return loggers } + +var ( + dunno = []byte("???") + centerDot = []byte("·") + dot = []byte(".") + slash = []byte("/") +) + +// Stack returns a nicely formatted stack frame, skipping skip frames. +func Stack(skip int) []byte { + buf := new(bytes.Buffer) // the returned data + // As we loop, we open files and read them. These variables record the currently + // loaded file. + var lines [][]byte + var lastFile string + for i := skip; ; i++ { // Skip the expected number of frames + pc, file, line, ok := runtime.Caller(i) + if !ok { + break + } + // Print this much at least. If we can't find the source, it won't show. + fmt.Fprintf(buf, "%s:%d (0x%x)\n", file, line, pc) + if file != lastFile { + data, err := ioutil.ReadFile(file) + if err != nil { + continue + } + lines = bytes.Split(data, []byte{'\n'}) + lastFile = file + } + fmt.Fprintf(buf, "\t%s: %s\n", function(pc), source(lines, line)) + } + return buf.Bytes() +} + +// function returns, if possible, the name of the function containing the PC. +func function(pc uintptr) []byte { + fn := runtime.FuncForPC(pc) + if fn == nil { + return dunno + } + name := []byte(fn.Name()) + // The name includes the path name to the package, which is unnecessary + // since the file name is already included. Plus, it has center dots. + // That is, we see + // runtime/debug.*T·ptrmethod + // and want + // *T.ptrmethod + // Also the package path might contains dot (e.g. code.google.com/...), + // so first eliminate the path prefix + if lastSlash := bytes.LastIndex(name, slash); lastSlash >= 0 { + name = name[lastSlash+1:] + } + if period := bytes.Index(name, dot); period >= 0 { + name = name[period+1:] + } + name = bytes.Replace(name, centerDot, dot, -1) + return name +} + +// source returns a space-trimmed slice of the n'th line. +func source(lines [][]byte, n int) []byte { + n-- // in stack trace, lines are 1-indexed but our array is 0-indexed + if n < 0 || n >= len(lines) { + return dunno + } + return bytes.TrimSpace(lines[n]) +}