// Test that Context.Log has a consistent function stack depth when binding // log.Valuers, regardless of how many times Context.With has been called or // whether Context.Log is called via an interface typed variable or a concrete // typed variable. func TestContextStackDepth(t *testing.T) { fn := fmt.Sprintf("%n", stack.Caller(0)) var output []interface{} logger := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error { output = keyvals return nil })) stackValuer := log.Valuer(func() interface{} { for i, c := range stack.Trace() { if fmt.Sprintf("%n", c) == fn { return i } } t.Fatal("Test function not found in stack trace.") return nil }) concrete := log.NewContext(logger).With("stack", stackValuer) var iface log.Logger = concrete // Call through interface to get baseline. iface.Log("k", "v") want := output[1].(int) for len(output) < 10 { concrete.Log("k", "v") if have := output[1]; have != want { t.Errorf("%d Withs: have %v, want %v", len(output)/2-1, have, want) } iface.Log("k", "v") if have := output[1]; have != want { t.Errorf("%d Withs: have %v, want %v", len(output)/2-1, have, want) } wrapped := log.NewContext(concrete) wrapped.Log("k", "v") if have := output[1]; have != want { t.Errorf("%d Withs: have %v, want %v", len(output)/2-1, have, want) } concrete = concrete.With("k", "v") iface = concrete } }
func TestContextMissingValue(t *testing.T) { t.Parallel() var output []interface{} logger := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error { output = keyvals return nil })) lc := log.NewContext(logger) lc.Log("k") if want, have := 2, len(output); want != have { t.Errorf("want len(output) == %v, have %v", want, have) } if want, have := log.ErrMissingValue, output[1]; want != have { t.Errorf("want %#v, have %#v", want, have) } lc.With("k1").WithPrefix("k0").Log("k2") if want, have := 6, len(output); want != have { t.Errorf("want len(output) == %v, have %v", want, have) } for i := 1; i < 6; i += 2 { if want, have := log.ErrMissingValue, output[i]; want != have { t.Errorf("want output[%d] == %#v, have %#v", i, want, have) } } }
func TestContext(t *testing.T) { t.Parallel() buf := &bytes.Buffer{} logger := log.NewLogfmtLogger(buf) kvs := []interface{}{"a", 123} lc := log.NewContext(logger).With(kvs...) kvs[1] = 0 // With should copy its key values lc = lc.With("b", "c") // With should stack if err := lc.Log("msg", "message"); err != nil { t.Fatal(err) } if want, have := "a=123 b=c msg=message\n", buf.String(); want != have { t.Errorf("\nwant: %shave: %s", want, have) } buf.Reset() lc = lc.WithPrefix("p", "first") if err := lc.Log("msg", "message"); err != nil { t.Fatal(err) } if want, have := "p=first a=123 b=c msg=message\n", buf.String(); want != have { t.Errorf("\nwant: %shave: %s", want, have) } }
func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) { lc := log.NewContext(logger).With("common_key", "common_value") b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { f(lc) } }
func TestNopLogger(t *testing.T) { logger := log.NewNopLogger() if err := logger.Log("abc", 123); err != nil { t.Error(err) } if err := log.NewContext(logger).With("def", "ghi").Log(); err != nil { t.Error(err) } }
func BenchmarkValueBindingTimestamp(b *testing.B) { logger := log.NewNopLogger() lc := log.NewContext(logger).With("ts", log.DefaultTimestamp) b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { lc.Log("k", "v") } }
func BenchmarkOneWith(b *testing.B) { logger := log.NewNopLogger() lc := log.NewContext(logger).With("k", "v") b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { lc.Log("k", "v") } }
func ExampleContext() { logger := log.NewLogfmtLogger(os.Stdout) logger.Log("foo", 123) ctx := log.NewContext(logger).With("level", "info") ctx.Log() ctx = ctx.With("msg", "hello") ctx.Log() ctx.With("a", 1).Log("b", 2) // Output: // foo=123 // level=info // level=info msg=hello // level=info msg=hello a=1 b=2 }
// New creates a new leveled logger, wrapping the passed logger. func New(logger log.Logger, options ...Option) Levels { l := Levels{ ctx: log.NewContext(logger), levelKey: "level", debugValue: "debug", infoValue: "info", warnValue: "warn", errorValue: "error", critValue: "crit", } for _, option := range options { option(&l) } return l }
func TestValueBinding(t *testing.T) { var output []interface{} logger := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error { output = keyvals return nil })) start := time.Date(2015, time.April, 25, 0, 0, 0, 0, time.UTC) now := start mocktime := func() time.Time { now = now.Add(time.Second) return now } lc := log.NewContext(logger).With("ts", log.Timestamp(mocktime), "caller", log.DefaultCaller) lc.Log("foo", "bar") timestamp, ok := output[1].(time.Time) if !ok { t.Fatalf("want time.Time, have %T", output[1]) } if want, have := start.Add(time.Second), timestamp; want != have { t.Errorf("output[1]: want %v, have %v", want, have) } if want, have := "value_test.go:28", fmt.Sprint(output[3]); want != have { t.Errorf("output[3]: want %s, have %s", want, have) } // A second attempt to confirm the bindings are truly dynamic. lc.Log("foo", "bar") timestamp, ok = output[1].(time.Time) if !ok { t.Fatalf("want time.Time, have %T", output[1]) } if want, have := start.Add(2*time.Second), timestamp; want != have { t.Errorf("output[1]: want %v, have %v", want, have) } if want, have := "value_test.go:41", fmt.Sprint(output[3]); want != have { t.Errorf("output[3]: want %s, have %s", want, have) } }
// Test that With returns a Logger safe for concurrent use. This test // validates that the stored logging context does not get corrupted when // multiple clients concurrently log additional keyvals. // // This test must be run with go test -cpu 2 (or more) to achieve its goal. func TestWithConcurrent(t *testing.T) { // Create some buckets to count how many events each goroutine logs. const goroutines = 8 counts := [goroutines]int{} // This logger extracts a goroutine id from the last value field and // increments the referenced bucket. logger := log.LoggerFunc(func(kv ...interface{}) error { goroutine := kv[len(kv)-1].(int) counts[goroutine]++ return nil }) // With must be careful about handling slices that can grow without // copying the underlying array, so give it a challenge. l := log.NewContext(logger).With(make([]interface{}, 0, 2)...) // Start logging concurrently. Each goroutine logs its id so the logger // can bucket the event counts. var wg sync.WaitGroup wg.Add(goroutines) const n = 10000 for i := 0; i < goroutines; i++ { go func(idx int) { defer wg.Done() for j := 0; j < n; j++ { l.Log("goroutineIdx", idx) } }(i) } wg.Wait() for bucket, have := range counts { if want := n; want != have { t.Errorf("bucket %d: want %d, have %d", bucket, want, have) // note Errorf } } }
func TestValueBinding_loggingZeroKeyvals(t *testing.T) { var output []interface{} logger := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error { output = keyvals return nil })) start := time.Date(2015, time.April, 25, 0, 0, 0, 0, time.UTC) now := start mocktime := func() time.Time { now = now.Add(time.Second) return now } logger = log.NewContext(logger).With("ts", log.Timestamp(mocktime)) logger.Log() timestamp, ok := output[1].(time.Time) if !ok { t.Fatalf("want time.Time, have %T", output[1]) } if want, have := start.Add(time.Second), timestamp; want != have { t.Errorf("output[1]: want %v, have %v", want, have) } // A second attempt to confirm the bindings are truly dynamic. logger.Log() timestamp, ok = output[1].(time.Time) if !ok { t.Fatalf("want time.Time, have %T", output[1]) } if want, have := start.Add(2*time.Second), timestamp; want != have { t.Errorf("output[1]: want %v, have %v", want, have) } }
package log_test import ( "testing" "github.com/gunjan5/Skywalker/Godeps/_workspace/src/github.com/go-kit/kit/log" ) func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) { lc := log.NewContext(logger).With("common_key", "common_value") b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { f(lc) } } var ( baseMessage = func(logger log.Logger) { logger.Log("foo_key", "foo_value") } withMessage = func(logger log.Logger) { log.NewContext(logger).With("a", "b").Log("c", "d") } )