Codebase list golang-github-go-kit-kit / ac852ff
Merge pull request #21 from peterbourgon/package-log-2 package log, alternate take Peter Bourgon 9 years ago
11 changed file(s) with 587 addition(s) and 0 deletion(s). Raw diff Collapse all Expand all
0 package log_test
1
2 import (
3 "testing"
4
5 "github.com/peterbourgon/gokit/log"
6 )
7
8 func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {
9 logger = log.With(logger, "common_key", "common_value")
10 b.ReportAllocs()
11 b.ResetTimer()
12 for i := 0; i < b.N; i++ {
13 f(logger)
14 }
15 }
16
17 var (
18 baseMessage = func(logger log.Logger) { logger.Log("foo_key", "foo_value") }
19 withMessage = func(logger log.Logger) { log.With(logger, "a", "b").Log("c", "d") }
20 )
0 package log
1
2 import (
3 "encoding/json"
4 "fmt"
5 "io"
6 )
7
8 type jsonLogger struct {
9 io.Writer
10 }
11
12 // NewJSONLogger returns a Logger that encodes keyvals to the Writer as a
13 // single JSON object.
14 func NewJSONLogger(w io.Writer) Logger {
15 return &jsonLogger{w}
16 }
17
18 func (l *jsonLogger) Log(keyvals ...interface{}) error {
19 if len(keyvals)%2 == 1 {
20 panic("odd number of keyvals")
21 }
22 m := make(map[string]interface{}, len(keyvals)/2)
23 for i := 0; i < len(keyvals); i += 2 {
24 merge(m, keyvals[i], keyvals[i+1])
25 }
26 return json.NewEncoder(l.Writer).Encode(m)
27 }
28
29 func merge(dst map[string]interface{}, k, v interface{}) map[string]interface{} {
30 var key string
31 switch x := k.(type) {
32 case string:
33 key = x
34 case fmt.Stringer:
35 key = x.String()
36 default:
37 key = fmt.Sprintf("%v", x)
38 }
39 if x, ok := v.(error); ok {
40 v = x.Error()
41 }
42 dst[key] = v
43 return dst
44 }
0 package log_test
1
2 import (
3 "bytes"
4 "errors"
5 "io/ioutil"
6 "testing"
7
8 "github.com/peterbourgon/gokit/log"
9 )
10
11 func TestJSONLogger(t *testing.T) {
12 buf := &bytes.Buffer{}
13 logger := log.NewJSONLogger(buf)
14 if err := logger.Log("err", errors.New("err"), "m", map[string]int{"0": 0}, "a", []int{1, 2, 3}); err != nil {
15 t.Fatal(err)
16 }
17 if want, have := `{"a":[1,2,3],"err":"err","m":{"0":0}}`+"\n", buf.String(); want != have {
18 t.Errorf("want %#v, have %#v", want, have)
19 }
20 }
21
22 func BenchmarkJSONLoggerSimple(b *testing.B) {
23 benchmarkRunner(b, log.NewJSONLogger(ioutil.Discard), baseMessage)
24 }
25
26 func BenchmarkJSONLoggerContextual(b *testing.B) {
27 benchmarkRunner(b, log.NewJSONLogger(ioutil.Discard), withMessage)
28 }
0 package log
1
2 // Levels provides a default set of leveled loggers.
3 type Levels struct {
4 Debug Logger
5 Info Logger
6 Error Logger
7 }
8
9 type levelOptions struct {
10 levelKey string
11 debugValue string
12 infoValue string
13 errorValue string
14 }
15
16 // LevelOption sets a parameter for leveled loggers.
17 type LevelOption func(*levelOptions)
18
19 // LevelKey sets the key for the field used to indicate log level. By default,
20 // the key is "level".
21 func LevelKey(key string) LevelOption {
22 return func(o *levelOptions) { o.levelKey = key }
23 }
24
25 // DebugLevelValue sets the value for the field used to indicate the debug log
26 // level. By default, the value is "DEBUG".
27 func DebugLevelValue(value string) LevelOption {
28 return func(o *levelOptions) { o.debugValue = value }
29 }
30
31 // InfoLevelValue sets the value for the field used to indicate the debug log
32 // level. By default, the value is "INFO".
33 func InfoLevelValue(value string) LevelOption {
34 return func(o *levelOptions) { o.infoValue = value }
35 }
36
37 // ErrorLevelValue sets the value for the field used to indicate the debug log
38 // level. By default, the value is "ERROR".
39 func ErrorLevelValue(value string) LevelOption {
40 return func(o *levelOptions) { o.errorValue = value }
41 }
42
43 // NewLevels returns a new set of leveled loggers based on the base logger.
44 func NewLevels(base Logger, options ...LevelOption) Levels {
45 opts := &levelOptions{
46 levelKey: "level",
47 debugValue: "DEBUG",
48 infoValue: "INFO",
49 errorValue: "ERROR",
50 }
51 for _, option := range options {
52 option(opts)
53 }
54 return Levels{
55 Debug: With(base, opts.levelKey, opts.debugValue),
56 Info: With(base, opts.levelKey, opts.infoValue),
57 Error: With(base, opts.levelKey, opts.errorValue),
58 }
59 }
0 package log_test
1
2 import (
3 "bytes"
4 "testing"
5
6 "github.com/peterbourgon/gokit/log"
7 )
8
9 func TestDefaultLevels(t *testing.T) {
10 buf := bytes.Buffer{}
11 levels := log.NewLevels(log.NewPrefixLogger(&buf))
12
13 levels.Debug.Log("msg", "👨") // of course you'd want to do this
14 if want, have := "level=DEBUG msg=👨\n", buf.String(); want != have {
15 t.Errorf("want %#v, have %#v", want, have)
16 }
17
18 buf.Reset()
19 levels.Info.Log("msg", "🚀")
20 if want, have := "level=INFO msg=🚀\n", buf.String(); want != have {
21 t.Errorf("want %#v, have %#v", want, have)
22 }
23
24 buf.Reset()
25 levels.Error.Log("msg", "🍵")
26 if want, have := "level=ERROR msg=🍵\n", buf.String(); want != have {
27 t.Errorf("want %#v, have %#v", want, have)
28 }
29 }
30
31 func TestModifiedLevels(t *testing.T) {
32 buf := bytes.Buffer{}
33 levels := log.NewLevels(
34 log.NewJSONLogger(&buf),
35 log.LevelKey("l"),
36 log.DebugLevelValue("⛄"),
37 log.InfoLevelValue("🌜"),
38 log.ErrorLevelValue("🌊"),
39 )
40 log.With(levels.Debug, "easter_island", "🗿").Log("msg", "💃💃💃")
41 if want, have := `{"easter_island":"🗿","l":"⛄","msg":"💃💃💃"}`+"\n", buf.String(); want != have {
42 t.Errorf("want %#v, have %#v", want, have)
43 }
44 }
0 package log
1
2 // Logger is the least-common-denominator interface for all log operations.
3 type Logger interface {
4 Log(keyvals ...interface{}) error
5 }
6
7 // With new, contextualized Logger with the passed keyvals already applied.
8 func With(logger Logger, keyvals ...interface{}) Logger {
9 if w, ok := logger.(Wither); ok {
10 return w.With(keyvals...)
11 }
12 return LoggerFunc(func(kvs ...interface{}) error {
13 return logger.Log(append(keyvals, kvs...)...)
14 })
15 }
16
17 // LoggerFunc is an adapter to allow use of ordinary functions as Loggers. If
18 // f is a function with the appropriate signature, LoggerFunc(f) is a Logger
19 // object that calls f.
20 type LoggerFunc func(...interface{}) error
21
22 // Log implements Logger by calling f(keyvals...).
23 func (f LoggerFunc) Log(keyvals ...interface{}) error {
24 return f(keyvals...)
25 }
26
27 // Wither describes an optimization that Logger implementations may make. If a
28 // Logger implements Wither, the package-level With function will invoke it
29 // when creating a new, contextual logger.
30 type Wither interface {
31 With(keyvals ...interface{}) Logger
32 }
0 package log_test
1
2 import (
3 "bytes"
4 "testing"
5
6 "github.com/peterbourgon/gokit/log"
7 )
8
9 func TestWith(t *testing.T) {
10 buf := &bytes.Buffer{}
11 logger := log.NewJSONLogger(buf)
12 logger = log.With(logger, "a", 123)
13 logger = log.With(logger, "b", "c") // With should stack
14 if err := logger.Log("msg", "message"); err != nil {
15 t.Fatal(err)
16 }
17 if want, have := `{"a":123,"b":"c","msg":"message"}`+"\n", buf.String(); want != have {
18 t.Errorf("want\n\t%#v, have\n\t%#v", want, have)
19 }
20 }
21
22 func TestWither(t *testing.T) {
23 logger := &mylogger{}
24 log.With(logger, "a", "b").Log("c", "d")
25 if want, have := 1, logger.withs; want != have {
26 t.Errorf("want %d, have %d", want, have)
27 }
28 }
29
30 type mylogger struct{ withs int }
31
32 func (l *mylogger) Log(keyvals ...interface{}) error { return nil }
33
34 func (l *mylogger) With(keyvals ...interface{}) log.Logger { l.withs++; return l }
0 package log
1
2 import (
3 "fmt"
4 "io"
5 )
6
7 type prefixLogger struct {
8 io.Writer
9 }
10
11 // NewPrefixLogger returns a basic logger that encodes keyvals as simple "k=v"
12 // pairs to the Writer.
13 func NewPrefixLogger(w io.Writer) Logger {
14 return &prefixLogger{w}
15 }
16
17 func (l prefixLogger) Log(keyvals ...interface{}) error {
18 if len(keyvals)%2 == 1 {
19 panic("odd number of keyvals")
20 }
21 for i := 0; i < len(keyvals); i += 2 {
22 if i != 0 {
23 if _, err := fmt.Fprint(l.Writer, " "); err != nil {
24 return err
25 }
26 }
27 if _, err := fmt.Fprintf(l.Writer, "%s=%v", keyvals[i], keyvals[i+1]); err != nil {
28 return err
29 }
30 }
31 if _, err := fmt.Fprintln(l.Writer); err != nil {
32 return err
33 }
34 return nil
35 }
0 package log_test
1
2 import (
3 "bytes"
4 "errors"
5 "io/ioutil"
6 "testing"
7
8 "github.com/peterbourgon/gokit/log"
9 )
10
11 func TestPrefixLogger(t *testing.T) {
12 buf := &bytes.Buffer{}
13 logger := log.NewPrefixLogger(buf)
14
15 if err := logger.Log("hello", "world"); err != nil {
16 t.Fatal(err)
17 }
18 if want, have := "hello=world\n", buf.String(); want != have {
19 t.Errorf("want %#v, have %#v", want, have)
20 }
21
22 buf.Reset()
23 if err := logger.Log("a", 1, "err", errors.New("error")); err != nil {
24 t.Fatal(err)
25 }
26 if want, have := "a=1 err=error\n", buf.String(); want != have {
27 t.Errorf("want %#v, have %#v", want, have)
28 }
29
30 buf.Reset()
31 if err := logger.Log("std_map", map[int]int{1: 2}, "my_map", mymap{0: 0}); err != nil {
32 t.Fatal(err)
33 }
34 if want, have := "std_map=map[1:2] my_map=special_behavior\n", buf.String(); want != have {
35 t.Errorf("want %#v, have %#v", want, have)
36 }
37 }
38
39 type mymap map[int]int
40
41 func (m mymap) String() string { return "special_behavior" }
42
43 func BenchmarkPrefixLoggerSimple(b *testing.B) {
44 benchmarkRunner(b, log.NewPrefixLogger(ioutil.Discard), baseMessage)
45 }
46
47 func BenchmarkPrefixLoggerContextual(b *testing.B) {
48 benchmarkRunner(b, log.NewPrefixLogger(ioutil.Discard), withMessage)
49 }
0 package log
1
2 import (
3 "io"
4 "regexp"
5 )
6
7 // StdlibWriter wraps a Logger and allows it to be passed to the stdlib
8 // logger's SetOutput. It will extract date/timestamps, filenames, and
9 // messages, and place them under relevant keys.
10 type StdlibWriter struct {
11 Logger
12 timestampKey string
13 fileKey string
14 messageKey string
15 }
16
17 // StdlibWriterOption sets a parameter for the StdlibWriter.
18 type StdlibWriterOption func(*StdlibWriter)
19
20 // TimestampKey sets the key for the timestamp field. By default, it's "ts".
21 func TimestampKey(key string) StdlibWriterOption {
22 return func(w *StdlibWriter) { w.timestampKey = key }
23 }
24
25 // FileKey sets the key for the file and line field. By default, it's "file".
26 func FileKey(key string) StdlibWriterOption {
27 return func(w *StdlibWriter) { w.fileKey = key }
28 }
29
30 // MessageKey sets the key for the actual log message. By default, it's "msg".
31 func MessageKey(key string) StdlibWriterOption {
32 return func(w *StdlibWriter) { w.messageKey = key }
33 }
34
35 // NewStdlibWriter returns a new StdlibWriter wrapper around the passed
36 // logger. It's designed to be passed to log.SetOutput.
37 func NewStdlibWriter(logger Logger, options ...StdlibWriterOption) io.Writer {
38 w := StdlibWriter{
39 Logger: logger,
40 timestampKey: "ts",
41 fileKey: "file",
42 messageKey: "msg",
43 }
44 for _, option := range options {
45 option(&w)
46 }
47 return w
48 }
49
50 func (w StdlibWriter) Write(p []byte) (int, error) {
51 result := subexps(p)
52 keyvals := []interface{}{}
53 var timestamp string
54 if date, ok := result["date"]; ok && date != "" {
55 timestamp = date
56 }
57 if time, ok := result["time"]; ok && time != "" {
58 if timestamp != "" {
59 timestamp += " "
60 }
61 timestamp += time
62 }
63 if timestamp != "" {
64 keyvals = append(keyvals, w.timestampKey, timestamp)
65 }
66 if file, ok := result["file"]; ok && file != "" {
67 keyvals = append(keyvals, w.fileKey, file)
68 }
69 if msg, ok := result["msg"]; ok {
70 keyvals = append(keyvals, w.messageKey, msg)
71 }
72 if err := w.Logger.Log(keyvals...); err != nil {
73 return 0, err
74 }
75 return len(p), nil
76 }
77
78 const (
79 logRegexpDate = `(?P<date>[0-9]{4}/[0-9]{2}/[0-9]{2})?[ ]?`
80 logRegexpTime = `(?P<time>[0-9]{2}:[0-9]{2}:[0-9]{2}(\.[0-9]+)?)?[ ]?`
81 logRegexpFile = `(?P<file>[^:]+:[0-9]+)?`
82 logRegexpMsg = `(: )?(?P<msg>.*)`
83 )
84
85 var (
86 logRegexp = regexp.MustCompile(logRegexpDate + logRegexpTime + logRegexpFile + logRegexpMsg)
87 )
88
89 func subexps(line []byte) map[string]string {
90 m := logRegexp.FindSubmatch(line)
91 if len(m) < len(logRegexp.SubexpNames()) {
92 return map[string]string{}
93 }
94 result := map[string]string{}
95 for i, name := range logRegexp.SubexpNames() {
96 result[name] = string(m[i])
97 }
98 return result
99 }
0 package log
1
2 import (
3 "bytes"
4 "fmt"
5 "log"
6 "testing"
7 "time"
8 )
9
10 func TestStdlibWriterUsage(t *testing.T) {
11 buf := &bytes.Buffer{}
12 logger := NewPrefixLogger(buf)
13 writer := NewStdlibWriter(logger)
14 log.SetOutput(writer)
15
16 now := time.Now()
17 date := now.Format("2006/01/02")
18 time := now.Format("15:04:05")
19
20 for flag, want := range map[int]string{
21 0: "msg=hello\n",
22 log.Ldate: "ts=" + date + " msg=hello\n",
23 log.Ltime: "ts=" + time + " msg=hello\n",
24 log.Ldate | log.Ltime: "ts=" + date + " " + time + " msg=hello\n",
25 log.Lshortfile: "file=stdlib_writer_test.go:32 msg=hello\n",
26 log.Lshortfile | log.Ldate: "ts=" + date + " file=stdlib_writer_test.go:32 msg=hello\n",
27 log.Lshortfile | log.Ldate | log.Ltime: "ts=" + date + " " + time + " file=stdlib_writer_test.go:32 msg=hello\n",
28 } {
29 buf.Reset()
30 log.SetFlags(flag)
31 log.Print("hello")
32 if have := buf.String(); want != have {
33 t.Errorf("flag=%d: want %#v, have %#v", flag, want, have)
34 }
35 }
36 }
37
38 func TestStdLibWriterExtraction(t *testing.T) {
39 buf := &bytes.Buffer{}
40 logger := NewPrefixLogger(buf)
41 writer := NewStdlibWriter(logger)
42 for input, want := range map[string]string{
43 "hello": "msg=hello\n",
44 "2009/01/23: hello": "ts=2009/01/23 msg=hello\n",
45 "2009/01/23 01:23:23: hello": "ts=2009/01/23 01:23:23 msg=hello\n",
46 "01:23:23: hello": "ts=01:23:23 msg=hello\n",
47 "2009/01/23 01:23:23.123123: hello": "ts=2009/01/23 01:23:23.123123 msg=hello\n",
48 "2009/01/23 01:23:23.123123 /a/b/c/d.go:23: hello": "ts=2009/01/23 01:23:23.123123 file=/a/b/c/d.go:23 msg=hello\n",
49 "01:23:23.123123 /a/b/c/d.go:23: hello": "ts=01:23:23.123123 file=/a/b/c/d.go:23 msg=hello\n",
50 "2009/01/23 01:23:23 /a/b/c/d.go:23: hello": "ts=2009/01/23 01:23:23 file=/a/b/c/d.go:23 msg=hello\n",
51 "2009/01/23 /a/b/c/d.go:23: hello": "ts=2009/01/23 file=/a/b/c/d.go:23 msg=hello\n",
52 "/a/b/c/d.go:23: hello": "file=/a/b/c/d.go:23 msg=hello\n",
53 } {
54 buf.Reset()
55 fmt.Fprintf(writer, input)
56 if have := buf.String(); want != have {
57 t.Errorf("%q: want %#v, have %#v", input, want, have)
58 }
59 }
60 }
61
62 func TestStdlibWriterSubexps(t *testing.T) {
63 for input, wantMap := range map[string]map[string]string{
64 "hello world": map[string]string{
65 "date": "",
66 "time": "",
67 "file": "",
68 "msg": "hello world",
69 },
70 "2009/01/23: hello world": map[string]string{
71 "date": "2009/01/23",
72 "time": "",
73 "file": "",
74 "msg": "hello world",
75 },
76 "2009/01/23 01:23:23: hello world": map[string]string{
77 "date": "2009/01/23",
78 "time": "01:23:23",
79 "file": "",
80 "msg": "hello world",
81 },
82 "01:23:23: hello world": map[string]string{
83 "date": "",
84 "time": "01:23:23",
85 "file": "",
86 "msg": "hello world",
87 },
88 "2009/01/23 01:23:23.123123: hello world": map[string]string{
89 "date": "2009/01/23",
90 "time": "01:23:23.123123",
91 "file": "",
92 "msg": "hello world",
93 },
94 "2009/01/23 01:23:23.123123 /a/b/c/d.go:23: hello world": map[string]string{
95 "date": "2009/01/23",
96 "time": "01:23:23.123123",
97 "file": "/a/b/c/d.go:23",
98 "msg": "hello world",
99 },
100 "01:23:23.123123 /a/b/c/d.go:23: hello world": map[string]string{
101 "date": "",
102 "time": "01:23:23.123123",
103 "file": "/a/b/c/d.go:23",
104 "msg": "hello world",
105 },
106 "2009/01/23 01:23:23 /a/b/c/d.go:23: hello world": map[string]string{
107 "date": "2009/01/23",
108 "time": "01:23:23",
109 "file": "/a/b/c/d.go:23",
110 "msg": "hello world",
111 },
112 "2009/01/23 /a/b/c/d.go:23: hello world": map[string]string{
113 "date": "2009/01/23",
114 "time": "",
115 "file": "/a/b/c/d.go:23",
116 "msg": "hello world",
117 },
118 "/a/b/c/d.go:23: hello world": map[string]string{
119 "date": "",
120 "time": "",
121 "file": "/a/b/c/d.go:23",
122 "msg": "hello world",
123 },
124 } {
125 haveMap := subexps([]byte(input))
126 for key, want := range wantMap {
127 if have := haveMap[key]; want != have {
128 t.Errorf("%q: %q: want %q, have %q", input, key, want, have)
129 }
130 }
131 }
132 }