Merge pull request #90 from dyweb/log/v2.5/init

[log] Refactor and measure performance using benchmark

- reduce handler interface to 2 methods, previously there was 7 for the sake of better performance
- use logger registry and only maintain tree for special loggers Fix #33 Fix #78
- allow set caller skip Fix #86
- support escape string in json handler
- add benchmark, mainly modeled after zap Fix #88

.gitignore

@@ -1,3 +1,4 @@
 .idea
 vendor
-coverage.txt
+coverage.txt
+gommon-build

.travis.yml

@@ -3,6 +3,7 @@ sudo: false
 
 go:
   - "1.10"
+  - "1.11"
   - tip
 
 install:

Makefile

@@ -48,9 +48,13 @@ FLAGS = -X main.version=$(VERSION) -X main.commit=$(BUILD_COMMIT) -X main.buildT
 install:
 	go install -ldflags "$(FLAGS)" ./cmd/gommon
 
+.PHONY: build
+build:
+	go build -ldflags "$(FLAGS)" -o gommon-build ./cmd/gommon
+
 .PHONY: fmt
 fmt:
-	gofmt -d -l -w $(PKGST)
+	goimports -d -l -w $(PKGST)
 
 .PHONY: generate
 generate:

cmd/gommon/main.go

@@ -16,7 +16,8 @@ import (
 	"github.com/dyweb/gommon/util/logutil"
 )
 
-var log = dlog.NewApplicationLogger()
+var log, logReg = dlog.NewApplicationLoggerAndRegistry("gommon")
+
 var verbose = false
 var (
 	version   string
@@ -34,8 +35,8 @@ func main() {
 		Long:  "Generate go files for gommon",
 		PersistentPreRun: func(cmd *cobra.Command, args []string) {
 			if verbose {
-				dlog.SetLevelRecursive(log, dlog.DebugLevel)
-				dlog.EnableSourceRecursive(log)
+				dlog.SetLevel(logReg, dlog.DebugLevel)
+				dlog.EnableSource(logReg)
 			}
 		},
 		Run: func(cmd *cobra.Command, args []string) {
@@ -135,6 +136,6 @@ func genCmd() *cobra.Command {
 }
 
 func init() {
-	log.AddChild(logutil.Registry)
-	dlog.SetHandlerRecursive(log, cli.New(os.Stderr, true))
+	logReg.AddRegistry(logutil.Registry())
+	dlog.SetHandler(logReg, cli.New(os.Stderr, true))
 }

generator/generate.go

@@ -8,7 +8,7 @@ import (
 	"path/filepath"
 	"strings"
 
-	"gopkg.in/yaml.v2"
+	yaml "gopkg.in/yaml.v2"
 
 	"github.com/dyweb/gommon/errors"
 	"github.com/dyweb/gommon/noodle"

generator/pkg.go

@@ -15,7 +15,7 @@ const (
 	DefaultGeneratedFile = "gommon_generated.go"
 )
 
-var log = logutil.NewPackageLogger()
+var log, logReg = logutil.NewPackageLoggerAndRegistry()
 
 type ConfigFile struct {
 	// Loggers is helper methods on struct for gommon/log to build a tree for logger, this is subject to change

generator/shell.go

@@ -4,7 +4,7 @@ import (
 	"os"
 	"os/exec"
 
-	"github.com/kballard/go-shellquote"
+	shellquote "github.com/kballard/go-shellquote"
 
 	"github.com/dyweb/gommon/errors"
 	"github.com/dyweb/gommon/util/fsutil"

log/CHANGELOG.md

@@ -0,0 +1,10 @@
+# Changelog
+
+## 2018-12-08
+
+- remove logger relation ship from logger struct, use logger registry instead
+
+## 2018-11-25
+
+- reduce `Handler` interface method from 6 to 1, just a `HandleLog(level Level, now time.Time, msg string, source string, context Fields, fields Fields)`
+- add `Print`, `Printf` for drop in replacement of standard library like non leveled logging library

log/TODO.md

@@ -1,5 +1,9 @@
 # TODO
 
+## 2018-11-24
+
+- [ ] [#90](https://github.com/dyweb/gommon/pull/90) the long pending benchmark and refactor for adding context (fields to logger instance)
+
 ## 2018-05-02
 
 - [x] [#67](https://github.com/dyweb/gommon/issues/67) add example in doc 

log/_benchmarks/.gitignore

@@ -0,0 +1,3 @@
+*.out
+# binary generated for profile
+*.test

log/_benchmarks/Makefile

@@ -0,0 +1,12 @@
+# TODO: the dependency is from global go path ...
+bench:
+	go test -run none -bench . -benchtime 3s -benchmem -memprofile p.out
+bench-gommon:
+	go test -run none -bench=".*/gommon" -benchtime 3s -benchmem -memprofile p.out
+bench-gommon-no-fields:
+	go test -run none -bench="BenchmarkWithoutFieldsText/gommon.F" -benchtime 3s -benchmem -memprofile p.out
+bench-gommon-no-context-with-fields:
+	go test -run none -bench="BenchmarkNoContextWithFieldsJSON/gommon.F" -benchtime 3s -benchmem -memprofile p.out
+pprof-ui:
+# TODO: need to give it binary path otherwise it will throw error
+	go tool pprof -http=:8080 p.out

log/_benchmarks/README.md

@@ -0,0 +1,16 @@
+# Benchmark
+
+## Log libraries
+
+- [ ] TODO: k8s fork for glog https://github.com/kubernetes/klog , 
+they are also considering parent children logger https://github.com/kubernetes/klog/issues/22
+
+## Ref
+
+- zap https://github.com/uber-go/zap/tree/master/benchmarks
+  - first clone and put the repo to $GOPATH/src/go.uber.org/zap  they are not using github repo as import path
+- zerolog https://github.com/rs/logbench
+- https://hackernoon.com/does-logging-cause-cpu-load-a-test-of-all-the-golang-logging-libraries-34052240f90d
+  - it starts a http server to log and use a client to hit the server
+  - [x] it measure system call using `sudo strace -c -t -p $(pid)` and see context switches
+- https://medium.com/justforfunc/analyzing-the-performance-of-go-functions-with-benchmarks-60b8162e61c6