performance enhancement

[museghost]

no more Context

it is slow for iterating map[string]interface{} to parse. Instead of it, since []interface{} is used, no more converting or iterating required.

added logfmt

https://github.com/go-logfmt/logfmt

performance

1. using buffered IO -> to avoid a lot of system call
2. using more buffers of the channel -> when logs are bursted and the amount of logs is over the channel's buffer size, it blocks the application entirely.

real benchmark

         f22 := bufio.NewWriter(os.Stderr)
	// ligno (async)
	// Create new logger with some context and handlers.
	m := ligno.GetLoggerOptions("myLogger", ligno.LoggerOptions{
		Context:            ligno.Ctx{"always": "present"},
		Handler: ligno.StreamHandler(f22, ligno.LogFmtFormat()),
		Level:              ligno.INFO,
		BufferSize:         1024*1024,
		PreventPropagation: true,
	})

	m.Info("")

	for i:=0; i < 500001; i++  {
		m.Info("info message #11", "service", "task", "num", i)
		m.Debug("debug message #55", "service", "task", "num", i)
		m.Warning("warning message #99", "service", "task", "num", i)
	}

	m.Wait()
	f22.Flush()

logfmt

ts=2018-11-29T00:27:44.492299Z lvl=INFO msg="info message #11" always=present service=task num=0
ts=2018-11-29T00:27:45.338794Z lvl=WARN msg="warning message #99" always=present service=task num=500000

ts=2018-11-29T10:09:31.477032Z lvl=INFO msg="info message #11" always=present service=task num=0
ts=2018-11-29T10:09:32.376873Z lvl=WARN msg="warning message #99" always=present service=task num=500000

It takes around 1 sec for printing out 1,000,000 messages

json

{"always":"present","lvl":"INFO","msg":"info message #11","num":0,"service":"task","ts":"2018-11-29T00:41:58.920654Z"}
{"always":"present","lvl":"WARN","msg":"warning message #99","num":499999,"service":"task","ts":"2018-11-29T00:41:59.897195Z"}

It also takes around 1 sec as well

with line and file path

ts=2018-11-29T09:58:19.103698Z lvl=INFO msg="info message #11" always=present service=task num=0 file=/Volumes/data01/00_dev/go/src/aphrodite/bsappgo/bslog/bslog_test.go line=45
ts=2018-11-29T09:58:21.841292Z lvl=WARN msg="warning message #99" always=present service=task num=499999 file=/Volumes/data01/00_dev/go/src/aphrodite/bsappgo/bslog/bslog_test.go line=48

It consumes around 2.8 sec

{"always":"present","file":"/Volumes/data01/00_dev/go/src/aphrodite/bsappgo/bslog/bslog_test.go","line":45,"lvl":"INFO","msg":"info message #11","num":0,"service":"task","ts":"2018-11-29T10:07:08.736056Z"}
{"always":"present","file":"/Volumes/data01/00_dev/go/src/aphrodite/bsappgo/bslog/bslog_test.go","line":48,"lvl":"WARN","msg":"warning message #99","num":500000,"service":"task","ts":"2018-11-29T10:07:11.313044Z"}

it takes around 2.7 sec