Esempio n. 1
0
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)
		}
	}
}
Esempio n. 2
0
func TestKafkaErrors(t *testing.T) {
	p := newStubProducer(true)
	errs := make(chan []interface{}, len(spans))
	lg := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error {
		for i := 0; i < len(keyvals); i += 2 {
			if keyvals[i] == "result" && keyvals[i+1] == "failed to produce msg" {
				errs <- keyvals
			}
		}
		return nil
	}))
	c, err := zipkin.NewKafkaCollector(
		[]string{"192.0.2.10:9092"},
		zipkin.KafkaProducer(p),
		zipkin.KafkaLogger(lg),
	)
	if err != nil {
		t.Fatal(err)
	}
	for _, want := range spans {
		_ = collectSpan(t, c, p, want)
	}

	for i := 0; i < len(spans); i++ {
		select {
		case <-errs:
		case <-time.After(100 * time.Millisecond):
			t.Fatalf("errors not logged. got %d, wanted %d", i, len(spans))
		}
	}
}
Esempio n. 3
0
// 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) {
	t.Parallel()
	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
	}
}
Esempio n. 4
0
func TestValueBinding(t *testing.T) {
	t.Parallel()
	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:29", 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:42", fmt.Sprint(output[3]); want != have {
		t.Errorf("output[3]: want %s, have %s", want, have)
	}
}
Esempio n. 5
0
// 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
		}
	}
}
Esempio n. 6
0
func TestValueBinding_loggingZeroKeyvals(t *testing.T) {
	t.Parallel()
	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)
	}
}
Esempio n. 7
0
package log_test

import (
	"bytes"
	"sync"
	"testing"

	"github.com/go-kit/kit/log"
)

var discard = log.Logger(log.LoggerFunc(func(...interface{}) error { return nil }))

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")