make default logger closer to std, add docs

README.md

@@ -1,4 +1,4 @@
-# lgr - simple logger with basic levels [![Build Status](https://travis-ci.org/go-pkgz/lgr.svg?branch=master)](https://travis-ci.org/go-pkgz/lgr) [![Coverage Status](https://coveralls.io/repos/github/go-pkgz/lgr/badge.svg?branch=master)](https://coveralls.io/github/go-pkgz/lgr?branch=master)
+# lgr - simple logger with some extras [![Build Status](https://travis-ci.org/go-pkgz/lgr.svg?branch=master)](https://travis-ci.org/go-pkgz/lgr) [![Coverage Status](https://coveralls.io/repos/github/go-pkgz/lgr/badge.svg?branch=master)](https://coveralls.io/github/go-pkgz/lgr?branch=master) [![godoc](https://godoc.org/github.com/go-pkgz/lgr?status.svg)](https://godoc.org/github.com/go-pkgz/lgr)
 
 ## install
 
@@ -7,11 +7,42 @@
 ## usage
 
 ```go
-    l := lgr.New(lgr.Debug) // allow debug
+    l := lgr.New(lgr.Debug, lgr.Caller) // allow debug and caller info
     l.Logf("INFO some important err message, %v", err)
     l.Logf("DEBUG some less important err message, %v", err)
 ```
 
+output looks like this:
+```
+2018/01/07 13:02:34.000 INFO  {svc/handler.go:101 h.MyFunc1} some important err message, can't open file`
+2018/01/07 13:02:34.015 DEBUG {svc/handler.go:155 h.MyFunc2} some less important err message, file is too small`
+```
+
+_Without `lgr.Caller` it will drop `{caller}` part_
+
 ## details
 
-TODO: interface, options, panics
+### interfaces and default loggers
+
+- `lgr` package provides a single interface `lgr.L` with a single method `Logf(format string, args ...interface{})`. Function wrapper `lgr.Func` allows to make `lgr.L` from a function directly.
+- Default logger functionality can be used without `lgr.New`, but just `lgr.Printf`
+- Two predefined loggers available: `lgr.NoOp` (do-nothing logger) and `lgr.Std` (passing directly to stdlib log)
+
+### options
+
+`lgr.New` call accepts functional options:
+
+- `lgr.Debug` - turn debug mode on. This allows messages with "DEBUG" level (filtered overwise)
+- `lgr.Caller` - adds the caller info each message
+- `lgr.Out(io.Writer)` - sets the output writer, default `os.Stdout`
+- `lgr.Err(io.Writer)` - sets the error writer, default `os.Stderr`
+
+### levels
+
+`lgr.Logf` recognizes prefixes like "INFO" or "[INFO]" as levels. The full list of supported levels - "DEBUG", "INFO", "WARN", "ERROR", "PANIC" and "FATAL"
+
+- `DEBUG` will be filtered unless `lgr.Debug` option defined
+- `INFO` and `WARN` don't have any special behavior attached
+- `ERROR` sends messages to both out and err writers
+- "PANIC" and "FATAL" send messages to both out and err writers. In addition sends dump of callers and runtime info to err only, and call `os.Exit(1)`.
+

interface.go

@@ -2,6 +2,8 @@ package lgr
 
 import stdlog "log"
 
+var def = New(Debug) // default logger allow DEBUG but doesn't add caller info
+
 // L defines minimal interface used to log things
 type L interface {
 	Logf(format string, args ...interface{})
@@ -16,10 +18,10 @@ func (f Func) Logf(format string, args ...interface{}) { f(format, args...) }
 // NoOp logger
 var NoOp = Func(func(format string, args ...interface{}) {})
 
-// Std logger
+// Std logger sends to std default logger directly
 var Std = Func(func(format string, args ...interface{}) { stdlog.Printf(format, args...) })
 
 // Printf simplifies replacement of std logger
 func Printf(format string, args ...interface{}) {
-	Std.Logf(format, args...)
+	def.Logf(format, args...)
 }

interface_test.go

@@ -8,6 +8,7 @@ import (
 	"os"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 )
@@ -42,3 +43,16 @@ func TestNoOp(t *testing.T) {
 	NoOp.Logf("blah %s %d something", "str", 123)
 	assert.Equal(t, "", buff.String())
 }
+
+func TestDefault(t *testing.T) {
+	buff := bytes.NewBuffer([]byte{})
+	def.stdout = buff
+	def.now = func() time.Time { return time.Date(2018, 1, 7, 13, 2, 34, 0, time.Local) }
+	defer func() {
+		def.stdout = os.Stdout
+		def.now = time.Now
+	}()
+
+	Printf("[DEBUG] something 123 %s", "xyz")
+	assert.Equal(t, "2018/01/07 13:02:34.000 DEBUG something 123 xyz\n", buff.String())
+}

logger.go

@@ -17,6 +17,7 @@ type Logger struct {
 	stdout, stderr io.Writer
 	dbg            bool
 	lock           sync.Mutex
+	callers        bool
 	now            nowFn
 	fatal          panicFn
 }
@@ -27,7 +28,12 @@ type panicFn func()
 // New makes new leveled logger. Accepts dbg flag turing on info about the caller and allowing DEBUG messages/
 // Two writers can be passed optionally - first for out and second for err
 func New(options ...Option) *Logger {
-	res := Logger{now: time.Now, fatal: func() { os.Exit(1) }}
+	res := Logger{
+		now:    time.Now,
+		fatal:  func() { os.Exit(1) },
+		stdout: os.Stdout,
+		stderr: os.Stderr,
+	}
 	for _, opt := range options {
 		opt(&res)
 	}
@@ -45,7 +51,7 @@ func (l *Logger) Logf(format string, args ...interface{}) {
 	bld.WriteString(l.now().Format("2006/01/02 15:04:05.000 "))
 	bld.WriteString(lv)
 
-	if l.dbg {
+	if l.dbg && l.callers {
 		if pc, file, line, ok := runtime.Caller(1); ok {
 			fnameElems := strings.Split(file, "/")
 			funcNameElems := strings.Split(runtime.FuncForPC(pc).Name(), "/")
@@ -128,3 +134,8 @@ func Err(w io.Writer) Option {
 func Debug(l *Logger) {
 	l.dbg = true
 }
+
+// Caller adds caller info with func, file, and line number
+func Caller(l *Logger) {
+	l.callers = true
+}

logger_test.go

@@ -69,7 +69,7 @@ func TestLoggerWithDbg(t *testing.T) {
 	}
 
 	rout, rerr := bytes.NewBuffer([]byte{}), bytes.NewBuffer([]byte{})
-	l := New(Debug, Out(rout), Err(rerr))
+	l := New(Debug, Caller, Out(rout), Err(rerr))
 	l.now = func() time.Time { return time.Date(2018, 1, 7, 13, 2, 34, 0, time.Local) }
 
 	for i, tt := range tbl {
@@ -81,18 +81,26 @@ func TestLoggerWithDbg(t *testing.T) {
 			assert.Equal(t, tt.rerr, rerr.String())
 		})
 	}
+
+	l = New(Debug, Out(rout), Err(rerr)) // no caller
+	l.now = func() time.Time { return time.Date(2018, 1, 7, 13, 2, 34, 0, time.Local) }
+	rout.Reset()
+	rerr.Reset()
+	l.Logf("[DEBUG] something 123 %s", "err")
+	assert.Equal(t, "2018/01/07 13:02:34.000 DEBUG something 123 err\n", rout.String())
+	assert.Equal(t, "", rerr.String())
 }
 
 func TestLoggerWithPanic(t *testing.T) {
 	fatalCalls := 0
 	rout, rerr := bytes.NewBuffer([]byte{}), bytes.NewBuffer([]byte{})
-	l := New(Debug, Out(rout), Err(rerr))
+	l := New(Debug, Caller, Out(rout), Err(rerr))
 	l.now = func() time.Time { return time.Date(2018, 1, 7, 13, 2, 34, 0, time.Local) }
 	l.fatal = func() { fatalCalls++ }
 
 	l.Logf("[PANIC] oh my, panic now! %v", errors.New("bad thing happened"))
 	assert.Equal(t, 1, fatalCalls)
-	assert.Equal(t, "2018/01/07 13:02:34.000 PANIC {lgr/logger_test.go:93 lgr.TestLoggerWithPanic} oh my, panic now! bad thing happened\n", rout.String())
+	assert.Equal(t, "2018/01/07 13:02:34.000 PANIC {lgr/logger_test.go:101 lgr.TestLoggerWithPanic} oh my, panic now! bad thing happened\n", rout.String())
 
 	t.Logf(rerr.String())
 	assert.True(t, strings.HasPrefix(rerr.String(), "2018/01/07 13:02:34.000 PANIC"))
@@ -134,7 +142,7 @@ func BenchmarkNoDbg(b *testing.B) {
 func BenchmarkWithDbg(b *testing.B) {
 
 	rout, rerr := bytes.NewBuffer([]byte{}), bytes.NewBuffer([]byte{})
-	l := New(Debug, Out(rout), Err(rerr))
+	l := New(Debug, Caller, Out(rout), Err(rerr))
 	l.now = func() time.Time { return time.Date(2018, 1, 7, 13, 2, 34, 0, time.Local) }
 
 	e := errors.New("some error")