Commit b58baecbd83eae4a591eb38e720c5280ef6a416c - golang-github-go-kit-kit

+14

-14

examples/addsvc/cmd/addsvc/main.go less more

0		package main
	0	package main
1	1
2	2	import (
3	3	"context"

50	50	var logger log.Logger
51	51	{
52	52	logger = log.NewLogfmtLogger(os.Stdout)
53		logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC)
54		logger = log.NewContext(logger).With("caller", log.DefaultCaller)
	53	logger = log.With(logger, "ts", log.DefaultTimestampUTC)
	54	logger = log.With(logger, "caller", log.DefaultCaller)
55	55	}
56	56	logger.Log("msg", "hello")
57	57	defer logger.Log("msg", "goodbye")

85	85	var tracer stdopentracing.Tracer
86	86	{
87	87	if *zipkinAddr != "" {
88		logger := log.NewContext(logger).With("tracer", "ZipkinHTTP")
	88	logger := log.With(logger, "tracer", "ZipkinHTTP")
89	89	logger.Log("addr", *zipkinAddr)
90	90
91	91	// endpoint typically looks like: http://zipkinhost:9411/api/v1/spans

104	104	os.Exit(1)
105	105	}
106	106	} else if *zipkinKafkaAddr != "" {
107		logger := log.NewContext(logger).With("tracer", "ZipkinKafka")
	107	logger := log.With(logger, "tracer", "ZipkinKafka")
108	108	logger.Log("addr", *zipkinKafkaAddr)
109	109
110	110	collector, err := zipkin.NewKafkaCollector(

125	125	os.Exit(1)
126	126	}
127	127	} else if *appdashAddr != "" {
128		logger := log.NewContext(logger).With("tracer", "Appdash")
	128	logger := log.With(logger, "tracer", "Appdash")
129	129	logger.Log("addr", *appdashAddr)
130	130	tracer = appdashot.NewTracer(appdash.NewRemoteCollector(*appdashAddr))
131	131	} else if *lightstepToken != "" {
132		logger := log.NewContext(logger).With("tracer", "LightStep")
	132	logger := log.With(logger, "tracer", "LightStep")
133	133	logger.Log() // probably don't want to print out the token :)
134	134	tracer = lightstep.NewTracer(lightstep.Options{
135	135	AccessToken: *lightstepToken,
136	136	})
137	137	defer lightstep.FlushLightStepTracer(tracer)
138	138	} else {
139		logger := log.NewContext(logger).With("tracer", "none")
	139	logger := log.With(logger, "tracer", "none")
140	140	logger.Log()
141	141	tracer = stdopentracing.GlobalTracer() // no-op
142	142	}

154	154	var sumEndpoint endpoint.Endpoint
155	155	{
156	156	sumDuration := duration.With("method", "Sum")
157		sumLogger := log.NewContext(logger).With("method", "Sum")
	157	sumLogger := log.With(logger, "method", "Sum")
158	158
159	159	sumEndpoint = addsvc.MakeSumEndpoint(service)
160	160	sumEndpoint = opentracing.TraceServer(tracer, "Sum")(sumEndpoint)

164	164	var concatEndpoint endpoint.Endpoint
165	165	{
166	166	concatDuration := duration.With("method", "Concat")
167		concatLogger := log.NewContext(logger).With("method", "Concat")
	167	concatLogger := log.With(logger, "method", "Concat")
168	168
169	169	concatEndpoint = addsvc.MakeConcatEndpoint(service)
170	170	concatEndpoint = opentracing.TraceServer(tracer, "Concat")(concatEndpoint)

189	189
190	190	// Debug listener.
191	191	go func() {
192		logger := log.NewContext(logger).With("transport", "debug")
	192	logger := log.With(logger, "transport", "debug")
193	193
194	194	m := http.NewServeMux()
195	195	m.Handle("/debug/pprof/", http.HandlerFunc(pprof.Index))

205	205
206	206	// HTTP transport.
207	207	go func() {
208		logger := log.NewContext(logger).With("transport", "HTTP")
	208	logger := log.With(logger, "transport", "HTTP")
209	209	h := addsvc.MakeHTTPHandler(endpoints, tracer, logger)
210	210	logger.Log("addr", *httpAddr)
211	211	errc <- http.ListenAndServe(*httpAddr, h)

213	213
214	214	// gRPC transport.
215	215	go func() {
216		logger := log.NewContext(logger).With("transport", "gRPC")
	216	logger := log.With(logger, "transport", "gRPC")
217	217
218	218	ln, err := net.Listen("tcp", *grpcAddr)
219	219	if err != nil {

231	231
232	232	// Thrift transport.
233	233	go func() {
234		logger := log.NewContext(logger).With("transport", "Thrift")
	234	logger := log.With(logger, "transport", "Thrift")
235	235
236	236	var protocolFactory thrift.TProtocolFactory
237	237	switch *thriftProtocol {

+2

-2

examples/apigateway/main.go less more

43	43	var logger log.Logger
44	44	{
45	45	logger = log.NewLogfmtLogger(os.Stderr)
46		logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC)
47		logger = log.NewContext(logger).With("caller", log.DefaultCaller)
	46	logger = log.With(logger, "ts", log.DefaultTimestampUTC)
	47	logger = log.With(logger, "caller", log.DefaultCaller)
48	48	}
49	49
50	50	// Service discovery domain. In this example we use Consul.

+4

-4

examples/profilesvc/cmd/profilesvc/main.go less more

0		package main
	0	package main
1	1
2	2	import (
3	3	"flag"

20	20	var logger log.Logger
21	21	{
22	22	logger = log.NewLogfmtLogger(os.Stderr)
23		logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC)
24		logger = log.NewContext(logger).With("caller", log.DefaultCaller)
	23	logger = log.With(logger, "ts", log.DefaultTimestampUTC)
	24	logger = log.With(logger, "caller", log.DefaultCaller)
25	25	}
26	26
27	27	var s profilesvc.Service

32	32
33	33	var h http.Handler
34	34	{
35		h = profilesvc.MakeHTTPHandler(s, log.NewContext(logger).With("component", "HTTP"))
	35	h = profilesvc.MakeHTTPHandler(s, log.With(logger, "component", "HTTP"))
36	36	}
37	37
38	38	errs := make(chan error)

+5

-5

examples/shipping/main.go less more

46	46	var logger log.Logger
47	47	logger = log.NewLogfmtLogger(os.Stderr)
48	48	logger = &serializedLogger{Logger: logger}
49		logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC)
	49	logger = log.With(logger, "ts", log.DefaultTimestampUTC)
50	50
51	51	var (
52	52	cargos = inmem.NewCargoRepository()

77	77
78	78	var bs booking.Service
79	79	bs = booking.NewService(cargos, locations, handlingEvents, rs)
80		bs = booking.NewLoggingService(log.NewContext(logger).With("component", "booking"), bs)
	80	bs = booking.NewLoggingService(log.With(logger, "component", "booking"), bs)
81	81	bs = booking.NewInstrumentingService(
82	82	kitprometheus.NewCounterFrom(stdprometheus.CounterOpts{
83	83	Namespace: "api",

96	96
97	97	var ts tracking.Service
98	98	ts = tracking.NewService(cargos, handlingEvents)
99		ts = tracking.NewLoggingService(log.NewContext(logger).With("component", "tracking"), ts)
	99	ts = tracking.NewLoggingService(log.With(logger, "component", "tracking"), ts)
100	100	ts = tracking.NewInstrumentingService(
101	101	kitprometheus.NewCounterFrom(stdprometheus.CounterOpts{
102	102	Namespace: "api",

115	115
116	116	var hs handling.Service
117	117	hs = handling.NewService(handlingEvents, handlingEventFactory, handlingEventHandler)
118		hs = handling.NewLoggingService(log.NewContext(logger).With("component", "handling"), hs)
	118	hs = handling.NewLoggingService(log.With(logger, "component", "handling"), hs)
119	119	hs = handling.NewInstrumentingService(
120	120	kitprometheus.NewCounterFrom(stdprometheus.CounterOpts{
121	121	Namespace: "api",

132	132	hs,
133	133	)
134	134
135		httpLogger := log.NewContext(logger).With("component", "http")
	135	httpLogger := log.With(logger, "component", "http")
136	136
137	137	mux := http.NewServeMux()
138	138

+1

-1

examples/stringsvc3/main.go less more

21	21
22	22	var logger log.Logger
23	23	logger = log.NewLogfmtLogger(os.Stderr)
24		logger = log.NewContext(logger).With("listen", *listen).With("caller", log.DefaultCaller)
	24	logger = log.With(logger, "listen", *listen, "caller", log.DefaultCaller)
25	25
26	26	fieldKeys := []string{"method", "error"}
27	27	requestCount := kitprometheus.NewCounterFrom(stdprometheus.CounterOpts{

+35

-36

log/README.md less more

0	0	# package log
1	1
2	2	`package log` provides a minimal interface for structured logging in services.
3		It may be wrapped to encode conventions, enforce type-safety, provide leveled logging, and so on.
4		It can be used for both typical application log events, and log-structured data streams.
	3	It may be wrapped to encode conventions, enforce type-safety, provide leveled
	4	logging, and so on. It can be used for both typical application log events,
	5	and log-structured data streams.
5	6
6	7	## Structured logging
7	8
8		Structured logging is, basically, conceding to the reality that logs are _data_,
9		and warrant some level of schematic rigor.
10		Using a stricter, key/value-oriented message format for our logs,
11		containing contextual and semantic information,
12		makes it much easier to get insight into the operational activity of the systems we build.
13		Consequently, `package log` is of the strong belief that
14		"[the benefits of structured logging outweigh the minimal effort involved](https://www.thoughtworks.com/radar/techniques/structured-logging)".
	9	Structured logging is, basically, conceding to the reality that logs are
	10	_data_, and warrant some level of schematic rigor. Using a stricter,
	11	key/value-oriented message format for our logs, containing contextual and
	12	semantic information, makes it much easier to get insight into the
	13	operational activity of the systems we build. Consequently, `package log` is
	14	of the strong belief that "[the benefits of structured logging outweigh the
	15	minimal effort involved](https://www.thoughtworks.com/radar/techniques/structured-logging)".
15	16
16		Migrating from unstructured to structured logging is probably a lot easier than you'd expect.
	17	Migrating from unstructured to structured logging is probably a lot easier
	18	than you'd expect.
17	19
18	20	```go
19	21	// Unstructured

36	38	// question="what is the meaning of life?" answer=42
37	39	```
38	40
39		### Log contexts
	41	### Contextual Loggers
40	42
41	43	```go
42	44	func main() {
43	45	var logger log.Logger
44	46	logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr))
45		logger = log.NewContext(logger).With("instance_id", 123)
	47	logger = log.With(logger, "instance_id", 123)
46	48
47	49	logger.Log("msg", "starting")
48		NewWorker(log.NewContext(logger).With("component", "worker")).Run()
49		NewSlacker(log.NewContext(logger).With("component", "slacker")).Run()
	50	NewWorker(log.With(logger, "component", "worker")).Run()
	51	NewSlacker(log.With(logger, "component", "slacker")).Run()
50	52	}
51	53
52	54	// Output:

76	78	// {"msg":"I sure like pie","ts":"2016/01/01 12:34:56"}
77	79	```
78	80
79		Or, if, for legacy reasons,
80		you need to pipe all of your logging through the stdlib log package,
81		you can redirect Go kit logger to the stdlib logger.
	81	Or, if, for legacy reasons, you need to pipe all of your logging through the
	82	stdlib log package, you can redirect Go kit logger to the stdlib logger.
82	83
83	84	```go
84	85	logger := kitlog.NewLogfmtLogger(kitlog.StdlibWriter{})

93	94	```go
94	95	var logger log.Logger
95	96	logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr))
96		logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
	97	logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
97	98
98	99	logger.Log("msg", "hello")
99	100

103	104
104	105	## Supported output formats
105	106
106		- [Logfmt](https://brandur.org/logfmt)
	107	- [Logfmt](https://brandur.org/logfmt) ([see also](https://blog.codeship.com/logfmt-a-log-format-thats-easy-to-read-and-write))
107	108	- JSON
108	109
109	110	## Enhancements

116	117	}
117	118	```
118	119
119		This interface, and its supporting code like [log.Context](https://godoc.org/github.com/go-kit/kit/log#Context),
120		is the product of much iteration and evaluation.
121		For more details on the evolution of the Logger interface,
122		see [The Hunt for a Logger Interface](http://go-talks.appspot.com/github.com/ChrisHines/talks/structured-logging/structured-logging.slide#1),
123		a talk by [Chris Hines](https://github.com/ChrisHines).
	120	This interface, and its supporting code like is the product of much iteration
	121	and evaluation. For more details on the evolution of the Logger interface,
	122	see [The Hunt for a Logger Interface](http://go-talks.appspot.com/github.com/ChrisHines/talks/structured-logging/structured-logging.slide#1),
	123	a talk by [Chris Hines](https://github.com/ChrisHines).
124	124	Also, please see
125		[#63](https://github.com/go-kit/kit/issues/63),
126		[#76](https://github.com/go-kit/kit/pull/76),
127		[#131](https://github.com/go-kit/kit/issues/131),
128		[#157](https://github.com/go-kit/kit/pull/157),
129		[#164](https://github.com/go-kit/kit/issues/164), and
130		[#252](https://github.com/go-kit/kit/pull/252)
131		to review historical conversations about package log and the Logger interface.
	125	[#63](https://github.com/go-kit/kit/issues/63),
	126	[#76](https://github.com/go-kit/kit/pull/76),
	127	[#131](https://github.com/go-kit/kit/issues/131),
	128	[#157](https://github.com/go-kit/kit/pull/157),
	129	[#164](https://github.com/go-kit/kit/issues/164), and
	130	[#252](https://github.com/go-kit/kit/pull/252)
	131	to review historical conversations about package log and the Logger interface.
132	132
133	133	Value-add packages and suggestions,
134		like improvements to [the leveled logger](https://godoc.org/github.com/go-kit/kit/log/levels),
135		are of course welcome.
136		Good proposals should
	134	like improvements to [the leveled logger](https://godoc.org/github.com/go-kit/kit/log/level),
	135	are of course welcome. Good proposals should
137	136
138		- Be composable with [log.Context](https://godoc.org/github.com/go-kit/kit/log#Context),
139		- Not break the behavior of [log.Caller](https://godoc.org/github.com/go-kit/kit/log#Caller) in any wrapped context, and
	137	- Be composable with [contextual loggers](https://godoc.org/github.com/go-kit/kit/log#With),
	138	- Not break the behavior of [log.Caller](https://godoc.org/github.com/go-kit/kit/log#Caller) in any wrapped contextual loggers, and
140	139	- Be friendly to packages that accept only an unadorned log.Logger.
141	140
142	141	## Benchmarks & comparisons

+2

-2

log/benchmark_test.go less more

6	6	)
7	7
8	8	func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {
9		lc := log.NewContext(logger).With("common_key", "common_value")
	9	lc := log.With(logger, "common_key", "common_value")
10	10	b.ReportAllocs()
11	11	b.ResetTimer()
12	12	for i := 0; i < b.N; i++ {

16	16
17	17	var (
18	18	baseMessage = func(logger log.Logger) { logger.Log("foo_key", "foo_value") }
19		withMessage = func(logger log.Logger) { log.NewContext(logger).With("a", "b").Log("c", "d") }
	19	withMessage = func(logger log.Logger) { log.With(logger, "a", "b").Log("c", "d") }
20	20	)

+8

-8

log/deprecated_levels/levels.go less more

6	6	// want a different set of levels, you can create your own levels type very
7	7	// easily, and you can elide the configuration.
8	8	type Levels struct {
9		ctx *log.Context
	9	logger log.Logger
10	10	levelKey string
11	11
12	12	// We have a choice between storing level values in string fields or

33	33	// New creates a new leveled logger, wrapping the passed logger.
34	34	func New(logger log.Logger, options ...Option) Levels {
35	35	l := Levels{
36		ctx: log.NewContext(logger),
	36	logger: logger,
37	37	levelKey: "level",
38	38
39	39	debugValue: "debug",

51	51	// With returns a new leveled logger that includes keyvals in all log events.
52	52	func (l Levels) With(keyvals ...interface{}) Levels {
53	53	return Levels{
54		ctx: l.ctx.With(keyvals...),
	54	logger: log.With(l.logger, keyvals...),
55	55	levelKey: l.levelKey,
56	56	debugValue: l.debugValue,
57	57	infoValue: l.infoValue,

63	63
64	64	// Debug returns a debug level logger.
65	65	func (l Levels) Debug() log.Logger {
66		return l.ctx.WithPrefix(l.levelKey, l.debugValue)
	66	return log.WithPrefix(l.logger, l.levelKey, l.debugValue)
67	67	}
68	68
69	69	// Info returns an info level logger.
70	70	func (l Levels) Info() log.Logger {
71		return l.ctx.WithPrefix(l.levelKey, l.infoValue)
	71	return log.WithPrefix(l.logger, l.levelKey, l.infoValue)
72	72	}
73	73
74	74	// Warn returns a warning level logger.
75	75	func (l Levels) Warn() log.Logger {
76		return l.ctx.WithPrefix(l.levelKey, l.warnValue)
	76	return log.WithPrefix(l.logger, l.levelKey, l.warnValue)
77	77	}
78	78
79	79	// Error returns an error level logger.
80	80	func (l Levels) Error() log.Logger {
81		return l.ctx.WithPrefix(l.levelKey, l.errorValue)
	81	return log.WithPrefix(l.logger, l.levelKey, l.errorValue)
82	82	}
83	83
84	84	// Crit returns a critical level logger.
85	85	func (l Levels) Crit() log.Logger {
86		return l.ctx.WithPrefix(l.levelKey, l.critValue)
	86	return log.WithPrefix(l.logger, l.levelKey, l.critValue)
87	87	}
88	88
89	89	// Option sets a parameter for leveled loggers.

+17

-17

log/doc.go less more

34	34	// idea to log simple values without formatting them. This practice allows
35	35	// the chosen logger to encode values in the most appropriate way.
36	36	//
37		// Log Context
	37	// Contextual Loggers
38	38	//
39		// A log context stores keyvals that it includes in all log events. Building
40		// appropriate log contexts reduces repetition and aids consistency in the
41		// resulting log output. We can use a context to improve the RunTask example.
	39	// A contextual logger stores keyvals that it includes in all log events.
	40	// Building appropriate contextual loggers reduces repetition and aids
	41	// consistency in the resulting log output. With and WithPrefix add context to
	42	// a logger. We can use With to improve the RunTask example.
42	43	//
43	44	// func RunTask(task Task, logger log.Logger) string {
44		// logger = log.NewContext(logger).With("taskID", task.ID)
	45	// logger = log.With(logger, "taskID", task.ID)
45	46	// logger.Log("event", "starting task")
46	47	// ...
47	48	// taskHelper(task.Cmd, logger)

50	51	// }
51	52	//
52	53	// The improved version emits the same log events as the original for the
53		// first and last calls to Log. The call to taskHelper highlights that a
54		// context may be passed as a logger to other functions. Each log event
55		// created by the called function will include the task.ID even though the
56		// function does not have access to that value. Using log contexts this way
57		// simplifies producing log output that enables tracing the life cycle of
58		// individual tasks. (See the Context example for the full code of the
59		// above snippet.)
	54	// first and last calls to Log. Passing the contextual logger to taskHelper
	55	// enables each log event created by taskHelper to include the task.ID even
	56	// though taskHelper does not have access to that value. Using contextual
	57	// loggers this way simplifies producing log output that enables tracing the
	58	// life cycle of individual tasks. (See the Contextual example for the full
	59	// code of the above snippet.)
60	60	//
61		// Dynamic Context Values
	61	// Dynamic Contextual Values
62	62	//
63		// A Valuer function stored in a log context generates a new value each time
64		// the context logs an event. The Valuer example demonstrates how this
65		// feature works.
	63	// A Valuer function stored in a contextual logger generates a new value each
	64	// time an event is logged. The Valuer example demonstrates how this feature
	65	// works.
66	66	//
67	67	// Valuers provide the basis for consistently logging timestamps and source
68	68	// code location. The log package defines several valuers for that purpose.

71	71	// entries contain a timestamp and source location looks like this:
72	72	//
73	73	// logger := log.NewLogfmtLogger(log.NewSyncWriter(os.Stdout))
74		// logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
	74	// logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
75	75	//
76	76	// Concurrent Safety
77	77	//

+4

-4

log/example_test.go less more

28	28	// taskID=1 event="task complete"
29	29	}
30	30
31		func Example_context() {
	31	func Example_contextual() {
32	32	logger := log.NewLogfmtLogger(os.Stdout)
33	33
34	34	type Task struct {

42	42	}
43	43
44	44	RunTask := func(task Task, logger log.Logger) {
45		logger = log.NewContext(logger).With("taskID", task.ID)
	45	logger = log.With(logger, "taskID", task.ID)
46	46	logger.Log("event", "starting task")
47	47
48	48	taskHelper(task.Cmd, logger)

67	67	return count
68	68	}
69	69
70		logger = log.NewContext(logger).With("count", log.Valuer(counter))
	70	logger = log.With(logger, "count", log.Valuer(counter))
71	71
72	72	logger.Log("call", "first")
73	73	logger.Log("call", "second")

87	87	return baseTime
88	88	}
89	89
90		logger = log.NewContext(logger).With("time", log.Timestamp(mockTime), "caller", log.DefaultCaller)
	90	logger = log.With(logger, "time", log.Timestamp(mockTime), "caller", log.DefaultCaller)
91	91
92	92	logger.Log("call", "first")
93	93	logger.Log("call", "second")

+1

-1

log/json_logger_test.go less more

12	12	t.Parallel()
13	13	buf := &bytes.Buffer{}
14	14	logger := log.NewJSONLogger(buf)
15		logger = log.NewContext(logger).With("caller", log.DefaultCaller)
	15	logger = log.With(logger, "caller", log.DefaultCaller)
16	16
17	17	if err := logger.Log(); err != nil {
18	18	t.Fatal(err)

+3

-3

log/level/benchmark_test.go less more

16	16	return l
17	17	}},
18	18	{"TimeContext", func(l log.Logger) log.Logger {
19		return log.NewContext(l).With("time", log.DefaultTimestampUTC)
	19	return log.With(l, "time", log.DefaultTimestampUTC)
20	20	}},
21	21	{"CallerContext", func(l log.Logger) log.Logger {
22		return log.NewContext(l).With("caller", log.DefaultCaller)
	22	return log.With(l, "caller", log.DefaultCaller)
23	23	}},
24	24	{"TimeCallerReqIDContext", func(l log.Logger) log.Logger {
25		return log.NewContext(l).With("time", log.DefaultTimestampUTC, "caller", log.DefaultCaller, "reqID", 29)
	25	return log.With(l, "time", log.DefaultTimestampUTC, "caller", log.DefaultCaller, "reqID", 29)
26	26	}},
27	27	}
28	28

+1

-1

log/level/example_test.go less more

11	11	// setup logger with level filter
12	12	logger := log.NewLogfmtLogger(os.Stdout)
13	13	logger = level.NewFilter(logger, level.AllowInfo())
14		logger = log.NewContext(logger).With("caller", log.DefaultCaller)
	14	logger = log.With(logger, "caller", log.DefaultCaller)
15	15
16	16	// use level helpers to log at different levels
17	17	level.Error(logger).Log("err", errors.New("bad data"))

+4

-4

log/level/level.go less more

3	3
4	4	// Error returns a logger that includes a Key/ErrorValue pair.
5	5	func Error(logger log.Logger) log.Logger {
6		return log.NewContext(logger).WithPrefix(Key(), ErrorValue())
	6	return log.WithPrefix(logger, Key(), ErrorValue())
7	7	}
8	8
9	9	// Warn returns a logger that includes a Key/WarnValue pair.
10	10	func Warn(logger log.Logger) log.Logger {
11		return log.NewContext(logger).WithPrefix(Key(), WarnValue())
	11	return log.WithPrefix(logger, Key(), WarnValue())
12	12	}
13	13
14	14	// Info returns a logger that includes a Key/InfoValue pair.
15	15	func Info(logger log.Logger) log.Logger {
16		return log.NewContext(logger).WithPrefix(Key(), InfoValue())
	16	return log.WithPrefix(logger, Key(), InfoValue())
17	17	}
18	18
19	19	// Debug returns a logger that includes a Key/DebugValue pair.
20	20	func Debug(logger log.Logger) log.Logger {
21		return log.NewContext(logger).WithPrefix(Key(), DebugValue())
	21	return log.WithPrefix(logger, Key(), DebugValue())
22	22	}
23	23
24	24	// NewFilter wraps next and implements level filtering. See the commentary on

+2

-2

log/level/level_test.go less more

143	143	var logger log.Logger
144	144	logger = log.NewLogfmtLogger(&buf)
145	145	logger = level.NewFilter(logger, level.AllowAll())
146		logger = log.NewContext(logger).With("caller", log.DefaultCaller)
	146	logger = log.With(logger, "caller", log.DefaultCaller)
147	147
148	148	level.Info(logger).Log("foo", "bar")
149	149	if want, have := `level=info caller=level_test.go:149 foo=bar`, strings.TrimSpace(buf.String()); want != have {

158	158	// to specify a higher callstack depth value.
159	159	var logger log.Logger
160	160	logger = log.NewLogfmtLogger(&buf)
161		logger = log.NewContext(logger).With("caller", log.Caller(5))
	161	logger = log.With(logger, "caller", log.Caller(5))
162	162	logger = level.NewFilter(logger, level.AllowAll())
163	163
164	164	level.Info(logger).Log("foo", "bar")

+78

-87

log/log.go less more

5	5	// log event from keyvals, a variadic sequence of alternating keys and values.
6	6	// Implementations must be safe for concurrent use by multiple goroutines. In
7	7	// particular, any implementation of Logger that appends to keyvals or
8		// modifies any of its elements must make a copy first.
	8	// modifies or retains any of its elements must make a copy first.
9	9	type Logger interface {
10	10	Log(keyvals ...interface{}) error
11	11	}

14	14	// the missing value.
15	15	var ErrMissingValue = errors.New("(MISSING)")
16	16
17		// NewContext returns a new Context that logs to logger.
18		func NewContext(logger Logger) *Context {
19		if c, ok := logger.(*Context); ok {
20		return c
	17	// With returns a new contextual logger with keyvals prepended to those passed
	18	// to calls to Log. If logger is also a contextual logger created by With or
	19	// WithPrefix, keyvals is appended to the existing context.
	20	//
	21	// The returned Logger replaces all value elements (odd indexes) containing a
	22	// Valuer with their generated value for each call to its Log method.
	23	func With(logger Logger, keyvals ...interface{}) Logger {
	24	if len(keyvals) == 0 {
	25	return logger
21	26	}
22		return &Context{logger: logger}
	27	l := newContext(logger)
	28	kvs := append(l.keyvals, keyvals...)
	29	if len(kvs)%2 != 0 {
	30	kvs = append(kvs, ErrMissingValue)
	31	}
	32	return &context{
	33	logger: l.logger,
	34	// Limiting the capacity of the stored keyvals ensures that a new
	35	// backing array is created if the slice must grow in Log or With.
	36	// Using the extra capacity without copying risks a data race that
	37	// would violate the Logger interface contract.
	38	keyvals: kvs[:len(kvs):len(kvs)],
	39	hasValuer: l.hasValuer \|\| containsValuer(keyvals),
	40	}
23	41	}
24	42
25		// Context must always have the same number of stack frames between calls to
	43	// WithPrefix returns a new contextual logger with keyvals prepended to those
	44	// passed to calls to Log. If logger is also a contextual logger created by
	45	// With or WithPrefix, keyvals is prepended to the existing context.
	46	//
	47	// The returned Logger replaces all value elements (odd indexes) containing a
	48	// Valuer with their generated value for each call to its Log method.
	49	func WithPrefix(logger Logger, keyvals ...interface{}) Logger {
	50	if len(keyvals) == 0 {
	51	return logger
	52	}
	53	l := newContext(logger)
	54	// Limiting the capacity of the stored keyvals ensures that a new
	55	// backing array is created if the slice must grow in Log or With.
	56	// Using the extra capacity without copying risks a data race that
	57	// would violate the Logger interface contract.
	58	n := len(l.keyvals) + len(keyvals)
	59	if len(keyvals)%2 != 0 {
	60	n++
	61	}
	62	kvs := make([]interface{}, 0, n)
	63	kvs = append(kvs, keyvals...)
	64	if len(kvs)%2 != 0 {
	65	kvs = append(kvs, ErrMissingValue)
	66	}
	67	kvs = append(kvs, l.keyvals...)
	68	return &context{
	69	logger: l.logger,
	70	keyvals: kvs,
	71	hasValuer: l.hasValuer \|\| containsValuer(keyvals),
	72	}
	73	}
	74
	75	// context is the Logger implementation returned by With and WithPrefix. It
	76	// wraps a Logger and holds keyvals that it includes in all log events. Its
	77	// Log method calls bindValues to generate values for each Valuer in the
	78	// context keyvals.
	79	//
	80	// A context must always have the same number of stack frames between calls to
26	81	// its Log method and the eventual binding of Valuers to their value. This
27	82	// requirement comes from the functional requirement to allow a context to
28		// resolve application call site information for a log.Caller stored in the
	83	// resolve application call site information for a Caller stored in the
29	84	// context. To do this we must be able to predict the number of logging
30	85	// functions on the stack when bindValues is called.
31	86	//
32		// Three implementation details provide the needed stack depth consistency.
33		// The first two of these details also result in better amortized performance,
34		// and thus make sense even without the requirements regarding stack depth.
35		// The third detail, however, is subtle and tied to the implementation of the
36		// Go compiler.
	87	// Two implementation details provide the needed stack depth consistency.
37	88	//
38		// 1. NewContext avoids introducing an additional layer when asked to
39		// wrap another Context.
40		// 2. With avoids introducing an additional layer by returning a newly
41		// constructed Context with a merged keyvals rather than simply
42		// wrapping the existing Context.
43		// 3. All of Context's methods take pointer receivers even though they
44		// do not mutate the Context.
45		//
46		// Before explaining the last detail, first some background. The Go compiler
47		// generates wrapper methods to implement the auto dereferencing behavior when
48		// calling a value method through a pointer variable. These wrapper methods
49		// are also used when calling a value method through an interface variable
50		// because interfaces store a pointer to the underlying concrete value.
51		// Calling a pointer receiver through an interface does not require generating
52		// an additional function.
53		//
54		// If Context had value methods then calling Context.Log through a variable
55		// with type Logger would have an extra stack frame compared to calling
56		// Context.Log through a variable with type Context. Using pointer receivers
57		// avoids this problem.
58
59		// A Context wraps a Logger and holds keyvals that it includes in all log
60		// events. When logging, a Context replaces all value elements (odd indexes)
61		// containing a Valuer with their generated value for each call to its Log
62		// method.
63		type Context struct {
	89	// 1. newContext avoids introducing an additional layer when asked to
	90	// wrap another context.
	91	// 2. With and WithPrefix avoid introducing an additional layer by
	92	// returning a newly constructed context with a merged keyvals rather
	93	// than simply wrapping the existing context.
	94	type context struct {
64	95	logger Logger
65	96	keyvals []interface{}
66	97	hasValuer bool
67	98	}
68	99
	100	func newContext(logger Logger) *context {
	101	if c, ok := logger.(*context); ok {
	102	return c
	103	}
	104	return &context{logger: logger}
	105	}
	106
69	107	// Log replaces all value elements (odd indexes) containing a Valuer in the
70	108	// stored context with their generated value, appends keyvals, and passes the
71	109	// result to the wrapped Logger.
72		func (l *Context) Log(keyvals ...interface{}) error {
	110	func (l *context) Log(keyvals ...interface{}) error {
73	111	kvs := append(l.keyvals, keyvals...)
74	112	if len(kvs)%2 != 0 {
75	113	kvs = append(kvs, ErrMissingValue)

85	123	return l.logger.Log(kvs...)
86	124	}
87	125
88		// With returns a new Context with keyvals appended to those of the receiver.
89		func (l Context) With(keyvals ...interface{}) Context {
90		if len(keyvals) == 0 {
91		return l
92		}
93		kvs := append(l.keyvals, keyvals...)
94		if len(kvs)%2 != 0 {
95		kvs = append(kvs, ErrMissingValue)
96		}
97		return &Context{
98		logger: l.logger,
99		// Limiting the capacity of the stored keyvals ensures that a new
100		// backing array is created if the slice must grow in Log or With.
101		// Using the extra capacity without copying risks a data race that
102		// would violate the Logger interface contract.
103		keyvals: kvs[:len(kvs):len(kvs)],
104		hasValuer: l.hasValuer \|\| containsValuer(keyvals),
105		}
106		}
107
108		// WithPrefix returns a new Context with keyvals prepended to those of the
109		// receiver.
110		func (l Context) WithPrefix(keyvals ...interface{}) Context {
111		if len(keyvals) == 0 {
112		return l
113		}
114		// Limiting the capacity of the stored keyvals ensures that a new
115		// backing array is created if the slice must grow in Log or With.
116		// Using the extra capacity without copying risks a data race that
117		// would violate the Logger interface contract.
118		n := len(l.keyvals) + len(keyvals)
119		if len(keyvals)%2 != 0 {
120		n++
121		}
122		kvs := make([]interface{}, 0, n)
123		kvs = append(kvs, keyvals...)
124		if len(kvs)%2 != 0 {
125		kvs = append(kvs, ErrMissingValue)
126		}
127		kvs = append(kvs, l.keyvals...)
128		return &Context{
129		logger: l.logger,
130		keyvals: kvs,
131		hasValuer: l.hasValuer \|\| containsValuer(keyvals),
132		}
133		}
134
135	126	// LoggerFunc is an adapter to allow use of ordinary functions as Loggers. If
136	127	// f is a function with the appropriate signature, LoggerFunc(f) is a Logger
137	128	// object that calls f.

+17

-36

log/log_test.go less more

15	15	logger := log.NewLogfmtLogger(buf)
16	16
17	17	kvs := []interface{}{"a", 123}
18		lc := log.NewContext(logger).With(kvs...)
	18	lc := log.With(logger, kvs...)
19	19	kvs[1] = 0 // With should copy its key values
20	20
21		lc = lc.With("b", "c") // With should stack
	21	lc = log.With(lc, "b", "c") // With should stack
22	22	if err := lc.Log("msg", "message"); err != nil {
23	23	t.Fatal(err)
24	24	}

27	27	}
28	28
29	29	buf.Reset()
30		lc = lc.WithPrefix("p", "first")
	30	lc = log.WithPrefix(lc, "p", "first")
31	31	if err := lc.Log("msg", "message"); err != nil {
32	32	t.Fatal(err)
33	33	}

44	44	return nil
45	45	}))
46	46
47		lc := log.NewContext(logger)
48
49		lc.Log("k")
50		if want, have := 2, len(output); want != have {
51		t.Errorf("want len(output) == %v, have %v", want, have)
52		}
53		if want, have := log.ErrMissingValue, output[1]; want != have {
54		t.Errorf("want %#v, have %#v", want, have)
55		}
56
57		lc.With("k1").WithPrefix("k0").Log("k2")
	47	log.WithPrefix(log.With(logger, "k1"), "k0").Log("k2")
58	48	if want, have := 6, len(output); want != have {
59	49	t.Errorf("want len(output) == %v, have %v", want, have)
60	50	}

65	55	}
66	56	}
67	57
68		// Test that Context.Log has a consistent function stack depth when binding
69		// log.Valuers, regardless of how many times Context.With has been called or
70		// whether Context.Log is called via an interface typed variable or a concrete
71		// typed variable.
	58	// Test that context.Log has a consistent function stack depth when binding
	59	// Valuers, regardless of how many times With has been called.
72	60	func TestContextStackDepth(t *testing.T) {
73	61	t.Parallel()
74	62	fn := fmt.Sprintf("%n", stack.Caller(0))

90	78	return nil
91	79	})
92	80
93		concrete := log.NewContext(logger).With("stack", stackValuer)
94		var iface log.Logger = concrete
	81	logger = log.With(logger, "stack", stackValuer)
95	82
96	83	// Call through interface to get baseline.
97		iface.Log("k", "v")
	84	logger.Log("k", "v")
98	85	want := output[1].(int)
99	86
100	87	for len(output) < 10 {
101		concrete.Log("k", "v")
	88	logger.Log("k", "v")
102	89	if have := output[1]; have != want {
103	90	t.Errorf("%d Withs: have %v, want %v", len(output)/2-1, have, want)
104	91	}
105	92
106		iface.Log("k", "v")
107		if have := output[1]; have != want {
108		t.Errorf("%d Withs: have %v, want %v", len(output)/2-1, have, want)
109		}
110
111		wrapped := log.NewContext(concrete)
	93	wrapped := log.With(logger)
112	94	wrapped.Log("k", "v")
113	95	if have := output[1]; have != want {
114	96	t.Errorf("%d Withs: have %v, want %v", len(output)/2-1, have, want)
115	97	}
116	98
117		concrete = concrete.With("k", "v")
118		iface = concrete
	99	logger = log.With(logger, "k", "v")
119	100	}
120	101	}
121	102

139	120
140	121	// With must be careful about handling slices that can grow without
141	122	// copying the underlying array, so give it a challenge.
142		l := log.NewContext(logger).With(make([]interface{}, 0, 2)...)
	123	l := log.With(logger, make([]interface{}, 0, 2)...)
143	124
144	125	// Start logging concurrently. Each goroutine logs its id so the logger
145	126	// can bucket the event counts.

174	155
175	156	func BenchmarkOneWith(b *testing.B) {
176	157	logger := log.NewNopLogger()
177		lc := log.NewContext(logger).With("k", "v")
	158	lc := log.With(logger, "k", "v")
178	159	b.ReportAllocs()
179	160	b.ResetTimer()
180	161	for i := 0; i < b.N; i++ {

184	165
185	166	func BenchmarkTwoWith(b *testing.B) {
186	167	logger := log.NewNopLogger()
187		lc := log.NewContext(logger).With("k", "v")
	168	lc := log.With(logger, "k", "v")
188	169	for i := 1; i < 2; i++ {
189		lc = lc.With("k", "v")
	170	lc = log.With(lc, "k", "v")
190	171	}
191	172	b.ReportAllocs()
192	173	b.ResetTimer()

197	178
198	179	func BenchmarkTenWith(b *testing.B) {
199	180	logger := log.NewNopLogger()
200		lc := log.NewContext(logger).With("k", "v")
	181	lc := log.With(logger, "k", "v")
201	182	for i := 1; i < 10; i++ {
202		lc = lc.With("k", "v")
	183	lc = log.With(lc, "k", "v")
203	184	}
204	185	b.ReportAllocs()
205	186	b.ResetTimer()

+1

-1

log/nop_logger_test.go less more

11	11	if err := logger.Log("abc", 123); err != nil {
12	12	t.Error(err)
13	13	}
14		if err := log.NewContext(logger).With("def", "ghi").Log(); err != nil {
	14	if err := log.With(logger, "def", "ghi").Log(); err != nil {
15	15	t.Error(err)
16	16	}
17	17	}

+2

-2

log/term/colorlogger_test.go less more

55	55
56	56	// copied from log/benchmark_test.go
57	57	func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {
58		lc := log.NewContext(logger).With("common_key", "common_value")
	58	lc := log.With(logger, "common_key", "common_value")
59	59	b.ReportAllocs()
60	60	b.ResetTimer()
61	61	for i := 0; i < b.N; i++ {

65	65
66	66	var (
67	67	baseMessage = func(logger log.Logger) { logger.Log("foo_key", "foo_value") }
68		withMessage = func(logger log.Logger) { log.NewContext(logger).With("a", "b").Log("c", "d") }
	68	withMessage = func(logger log.Logger) { log.With(logger, "a", "b").Log("c", "d") }
69	69	)
70	70
71	71	// copied from log/concurrency_test.go

+15

-13

log/value.go less more

5	5	"github.com/go-stack/stack"
6	6	)
7	7
8		// A Valuer generates a log value. When passed to Context.With in a value
9		// element (odd indexes), it represents a dynamic value which is re-evaluated
10		// with each log event.
	8	// A Valuer generates a log value. When passed to With or WithPrefix in a
	9	// value element (odd indexes), it represents a dynamic value which is re-
	10	// evaluated with each log event.
11	11	type Valuer func() interface{}
12	12
13	13	// bindValues replaces all value elements (odd indexes) containing a Valuer

38	38	return func() interface{} { return t() }
39	39	}
40	40
41		var (
42		// DefaultTimestamp is a Valuer that returns the current wallclock time,
43		// respecting time zones, when bound.
44		DefaultTimestamp Valuer = func() interface{} { return time.Now().Format(time.RFC3339Nano) }
45
46		// DefaultTimestampUTC is a Valuer that returns the current time in UTC
47		// when bound.
48		DefaultTimestampUTC Valuer = func() interface{} { return time.Now().UTC().Format(time.RFC3339Nano) }
49		)
50
51	41	// Caller returns a Valuer that returns a file and line from a specified depth
52	42	// in the callstack. Users will probably want to use DefaultCaller.
53	43	func Caller(depth int) Valuer {

55	45	}
56	46
57	47	var (
	48	// DefaultTimestamp is a Valuer that returns the current wallclock time,
	49	// respecting time zones, when bound.
	50	DefaultTimestamp = Valuer(func() interface{} {
	51	return time.Now().Format(time.RFC3339Nano)
	52	})
	53
	54	// DefaultTimestampUTC is a Valuer that returns the current time in UTC
	55	// when bound.
	56	DefaultTimestampUTC = Valuer(func() interface{} {
	57	return time.Now().UTC().Format(time.RFC3339Nano)
	58	})
	59
58	60	// DefaultCaller is a Valuer that returns the file and line where the Log
59	61	// method was invoked. It can only be used with log.With.
60	62	DefaultCaller = Caller(3)

+4

-4

log/value_test.go less more

23	23	return now
24	24	}
25	25
26		lc := log.NewContext(logger).With("ts", log.Timestamp(mocktime), "caller", log.DefaultCaller)
	26	lc := log.With(logger, "ts", log.Timestamp(mocktime), "caller", log.DefaultCaller)
27	27
28	28	lc.Log("foo", "bar")
29	29	timestamp, ok := output[1].(time.Time)

67	67	return now
68	68	}
69	69
70		logger = log.NewContext(logger).With("ts", log.Timestamp(mocktime))
	70	logger = log.With(logger, "ts", log.Timestamp(mocktime))
71	71
72	72	logger.Log()
73	73	timestamp, ok := output[1].(time.Time)

91	91
92	92	func BenchmarkValueBindingTimestamp(b *testing.B) {
93	93	logger := log.NewNopLogger()
94		lc := log.NewContext(logger).With("ts", log.DefaultTimestamp)
	94	lc := log.With(logger, "ts", log.DefaultTimestamp)
95	95	b.ReportAllocs()
96	96	b.ResetTimer()
97	97	for i := 0; i < b.N; i++ {

101	101
102	102	func BenchmarkValueBindingCaller(b *testing.B) {
103	103	logger := log.NewNopLogger()
104		lc := log.NewContext(logger).With("caller", log.DefaultCaller)
	104	lc := log.With(logger, "caller", log.DefaultCaller)
105	105	b.ReportAllocs()
106	106	b.ResetTimer()
107	107	for i := 0; i < b.N; i++ {

+2

-2

sd/consul/integration_test.go less more

45	45	subscriber := NewSubscriber(
46	46	client,
47	47	factory,
48		log.NewContext(logger).With("component", "subscriber"),
	48	log.With(logger, "component", "subscriber"),
49	49	r.Name,
50	50	r.Tags,
51	51	true,

63	63	}
64	64
65	65	// Build a registrar for r.
66		registrar := NewRegistrar(client, r, log.NewContext(logger).With("component", "registrar"))
	66	registrar := NewRegistrar(client, r, log.With(logger, "component", "registrar"))
67	67	registrar.Register()
68	68	defer registrar.Deregister()
69	69

+1

-1

sd/consul/registrar.go less more

20	20	return &Registrar{
21	21	client: client,
22	22	registration: r,
23		logger: log.NewContext(logger).With("service", r.Name, "tags", fmt.Sprint(r.Tags), "address", r.Address),
	23	logger: log.With(logger, "service", r.Name, "tags", fmt.Sprint(r.Tags), "address", r.Address),
24	24	}
25	25	}
26	26

+1

-1

sd/consul/subscriber.go less more

35	35	s := &Subscriber{
36	36	cache: cache.New(factory, logger),
37	37	client: client,
38		logger: log.NewContext(logger).With("service", service, "tags", fmt.Sprint(tags)),
	38	logger: log.With(logger, "service", service, "tags", fmt.Sprint(tags)),
39	39	service: service,
40	40	tags: tags,
41	41	passingOnly: passingOnly,

+2

-2

sd/etcd/integration_test.go less more

48	48	registrar := NewRegistrar(client, Service{
49	49	Key: key,
50	50	Value: value,
51		}, log.NewContext(log.NewLogfmtLogger(os.Stderr)).With("component", "registrar"))
	51	}, log.With(log.NewLogfmtLogger(os.Stderr), "component", "registrar"))
52	52
53	53	// Register our instance.
54	54	registrar.Register()

70	70	client,
71	71	prefix,
72	72	func(string) (endpoint.Endpoint, io.Closer, error) { return endpoint.Nop, nil, nil },
73		log.NewContext(log.NewLogfmtLogger(os.Stderr)).With("component", "subscriber"),
	73	log.With(log.NewLogfmtLogger(os.Stderr), "component", "subscriber"),
74	74	)
75	75	if err != nil {
76	76	t.Fatalf("NewSubscriber: %v", err)

+1

-4

sd/etcd/registrar.go less more

62	62	return &Registrar{
63	63	client: client,
64	64	service: service,
65		logger: log.NewContext(logger).With(
66		"key", service.Key,
67		"value", service.Value,
68		),
	65	logger: log.With(logger, "key", service.Key, "value", service.Value),
69	66	}
70	67	}
71	68

+1

-1

sd/zk/registrar.go less more

23	23	return &Registrar{
24	24	client: client,
25	25	service: service,
26		logger: log.NewContext(logger).With(
	26	logger: log.With(logger,
27	27	"service", service.Name,
28	28	"path", service.Path,
29	29	"data", string(service.Data),