Skip to content

Be consistent with span logging, set error=true and use otlog.Error #2970

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 6 commits into from
Aug 12, 2020
Merged

Be consistent with span logging, set error=true and use otlog.Error #2970

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
706985c
Make use of spanlogger when functions that generate spans result in an
cstyan Jul 31, 2020
2935b45
Add spanlogger Error to errcheck exclude
cstyan Aug 4, 2020
b51ed19
Review cleanup.
cstyan Aug 5, 2020
b5a91b6
Address more review feedback.
cstyan Aug 10, 2020
075f07c
We need nolint comments on these lines if we want to assign the ctx in
cstyan Aug 10, 2020
f2d02ea
Globally exclude SpanLogger.Error() errcheck
pracucci Aug 11, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion .errcheck-exclude
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,4 +2,5 @@ io/ioutil.WriteFile
io/ioutil.ReadFile
(github.com/go-kit/kit/log.Logger).Log
io.Copy
(github.com/opentracing/opentracing-go.Tracer).Inject
(github.com/opentracing/opentracing-go.Tracer).Inject
(*github.com/cortexproject/cortex/pkg/util/spanlogger.SpanLogger).Error
15 changes: 8 additions & 7 deletions pkg/chunk/cache/memcached.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,13 +11,13 @@ import (
"github.com/bradfitz/gomemcache/memcache"
"github.com/go-kit/kit/log"
"github.com/go-kit/kit/log/level"
opentracing "github.com/opentracing/opentracing-go"
otlog "github.com/opentracing/opentracing-go/log"
"github.com/prometheus/client_golang/prometheus"
"github.com/prometheus/client_golang/prometheus/promauto"
instr "github.com/weaveworks/common/instrument"

"github.com/cortexproject/cortex/pkg/util"
"github.com/cortexproject/cortex/pkg/util/spanlogger"
)

type observableVecCollector struct {
Expand Down Expand Up @@ -146,19 +146,20 @@ func (c *Memcached) Fetch(ctx context.Context, keys []string) (found []string, b

func (c *Memcached) fetch(ctx context.Context, keys []string) (found []string, bufs [][]byte, missed []string) {
var items map[string]*memcache.Item
err := instr.CollectedRequest(ctx, "Memcache.GetMulti", c.requestDuration, memcacheStatusCode, func(innerCtx context.Context) error {
sp := opentracing.SpanFromContext(innerCtx)
sp.LogFields(otlog.Int("keys requested", len(keys)))
const method = "Memcache.GetMulti"
err := instr.CollectedRequest(ctx, method, c.requestDuration, memcacheStatusCode, func(innerCtx context.Context) error {
log, _ := spanlogger.New(innerCtx, method)
log.LogFields(otlog.Int("keys requested", len(keys)))

var err error
items, err = c.memcache.GetMulti(keys)

sp.LogFields(otlog.Int("keys found", len(items)))
log.LogFields(otlog.Int("keys found", len(items)))

// Memcached returns partial results even on error.
if err != nil {
sp.LogFields(otlog.Error(err))
level.Error(c.logger).Log("msg", "Failed to get keys from memcached", "err", err)
log.Error(err)
level.Error(log).Log("msg", "Failed to get keys from memcached", "err", err)
}
return err
})
Expand Down
8 changes: 4 additions & 4 deletions pkg/chunk/gcp/bigtable_index_client.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,13 +13,13 @@ import (
"cloud.google.com/go/bigtable"
"github.com/go-kit/kit/log"
ot "github.com/opentracing/opentracing-go"
otlog "github.com/opentracing/opentracing-go/log"
"github.com/pkg/errors"

"github.com/cortexproject/cortex/pkg/chunk"
chunk_util "github.com/cortexproject/cortex/pkg/chunk/util"
"github.com/cortexproject/cortex/pkg/util"
"github.com/cortexproject/cortex/pkg/util/grpcclient"
"github.com/cortexproject/cortex/pkg/util/spanlogger"
)

const (
Expand Down Expand Up @@ -324,8 +324,8 @@ func (s *storageClientV1) QueryPages(ctx context.Context, queries []chunk.IndexQ
func (s *storageClientV1) query(ctx context.Context, query chunk.IndexQuery, callback chunk_util.Callback) error {
const null = string('\xff')

sp, ctx := ot.StartSpanFromContext(ctx, "QueryPages", ot.Tag{Key: "tableName", Value: query.TableName}, ot.Tag{Key: "hashValue", Value: query.HashValue})
defer sp.Finish()
log, ctx := spanlogger.New(ctx, "QueryPages", ot.Tag{Key: "tableName", Value: query.TableName}, ot.Tag{Key: "hashValue", Value: query.HashValue})
defer log.Finish()

table := s.client.Open(query.TableName)

Expand Down Expand Up @@ -358,7 +358,7 @@ func (s *storageClientV1) query(ctx context.Context, query chunk.IndexQuery, cal
return true
})
if err != nil {
sp.LogFields(otlog.String("error", err.Error()))
log.Error(err)
return errors.WithStack(err)
}
return nil
Expand Down
12 changes: 6 additions & 6 deletions pkg/chunk/util/parallel_chunk_fetch.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,10 @@ import (
"context"
"sync"

ot "github.com/opentracing/opentracing-go"
otlog "github.com/opentracing/opentracing-go/log"

"github.com/cortexproject/cortex/pkg/chunk"
"github.com/cortexproject/cortex/pkg/util/spanlogger"
)

const maxParallel = 1000
Expand All @@ -20,9 +20,9 @@ var decodeContextPool = sync.Pool{

// GetParallelChunks fetches chunks in parallel (up to maxParallel).
func GetParallelChunks(ctx context.Context, chunks []chunk.Chunk, f func(context.Context, *chunk.DecodeContext, chunk.Chunk) (chunk.Chunk, error)) ([]chunk.Chunk, error) {
sp, ctx := ot.StartSpanFromContext(ctx, "GetParallelChunks")
defer sp.Finish()
sp.LogFields(otlog.Int("chunks requested", len(chunks)))
log, ctx := spanlogger.New(ctx, "GetParallelChunks")
defer log.Finish()
log.LogFields(otlog.Int("chunks requested", len(chunks)))

queuedChunks := make(chan chunk.Chunk)

Expand Down Expand Up @@ -62,9 +62,9 @@ func GetParallelChunks(ctx context.Context, chunks []chunk.Chunk, f func(context
}
}

sp.LogFields(otlog.Int("chunks fetched", len(result)))
log.LogFields(otlog.Int("chunks fetched", len(result)))
if lastErr != nil {
sp.LogFields(otlog.Error(lastErr))
log.Error(lastErr)
}

// Return any chunks we did receive: a partial result may be useful
Expand Down
10 changes: 5 additions & 5 deletions pkg/querier/queryrange/query_range.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import (

"github.com/cortexproject/cortex/pkg/ingester/client"
"github.com/cortexproject/cortex/pkg/util"
"github.com/cortexproject/cortex/pkg/util/spanlogger"
)

// StatusSuccess Prometheus success result.
Expand Down Expand Up @@ -238,17 +239,16 @@ func (prometheusCodec) DecodeResponse(ctx context.Context, r *http.Response, _ R
body, _ := ioutil.ReadAll(r.Body)
return nil, httpgrpc.Errorf(r.StatusCode, string(body))
}

sp, _ := opentracing.StartSpanFromContext(ctx, "ParseQueryRangeResponse")
defer sp.Finish()
log, ctx := spanlogger.New(ctx, "ParseQueryRangeResponse") //nolint:ineffassign,staticcheck
defer log.Finish()

buf, err := ioutil.ReadAll(r.Body)
if err != nil {
sp.LogFields(otlog.Error(err))
log.Error(err)
return nil, httpgrpc.Errorf(http.StatusInternalServerError, "error decoding response: %v", err)
}

sp.LogFields(otlog.Int("bytes", len(buf)))
log.LogFields(otlog.Int("bytes", len(buf)))

var resp PrometheusResponse
if err := json.Unmarshal(buf, &resp); err != nil {
Expand Down
10 changes: 5 additions & 5 deletions pkg/querier/queryrange/results_cache.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -450,14 +450,14 @@ func (s resultsCache) get(ctx context.Context, key string) ([]Extent, bool) {
}

var resp CachedResponse
sp, _ := opentracing.StartSpanFromContext(ctx, "unmarshal-extent")
defer sp.Finish()
log, ctx := spanlogger.New(ctx, "unmarshal-extent") //nolint:ineffassign,staticcheck
defer log.Finish()

sp.LogFields(otlog.Int("bytes", len(bufs[0])))
log.LogFields(otlog.Int("bytes", len(bufs[0])))

if err := proto.Unmarshal(bufs[0], &resp); err != nil {
level.Error(s.logger).Log("msg", "error unmarshalling cached value", "err", err)
sp.LogFields(otlog.Error(err))
level.Error(log).Log("msg", "error unmarshalling cached value", "err", err)
log.Error(err)
return nil, false
}

Expand Down
7 changes: 3 additions & 4 deletions pkg/testexporter/correctness/simple.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,6 @@ import (
"time"

"github.com/go-kit/kit/log/level"
otlog "github.com/opentracing/opentracing-go/log"
v1 "github.com/prometheus/client_golang/api/prometheus/v1"
"github.com/prometheus/client_golang/prometheus"
"github.com/prometheus/client_golang/prometheus/promauto"
Expand Down Expand Up @@ -161,7 +160,7 @@ func verifySamples(log *spanlogger.SpanLogger, tc Case, pairs []model.SamplePair
} else {
sampleResult.WithLabelValues(tc.Name(), fail).Inc()
level.Error(log).Log("msg", "wrong value", "at", pair.Timestamp, "expected", tc.ExpectedValueAt(pair.Timestamp.Time()), "actual", pair.Value)
log.LogFields(otlog.Error(fmt.Errorf("wrong value")))
log.Error(fmt.Errorf("wrong value"))
return false
}
}
Expand All @@ -171,14 +170,14 @@ func verifySamples(log *spanlogger.SpanLogger, tc Case, pairs []model.SamplePair
expectedNumSamples := int(duration / cfg.ScrapeInterval)
if !epsilonCorrect(float64(len(pairs)), float64(expectedNumSamples), cfg.samplesEpsilon) {
level.Error(log).Log("msg", "wrong number of samples", "expected", expectedNumSamples, "actual", len(pairs))
log.LogFields(otlog.Error(fmt.Errorf("wrong number of samples")))
log.Error(fmt.Errorf("wrong number of samples"))
return false
}
} else {
expectedNumSamples := int(duration / cfg.ScrapeInterval)
if math.Abs(float64(expectedNumSamples-len(pairs))) > 2 {
level.Error(log).Log("msg", "wrong number of samples", "expected", expectedNumSamples, "actual", len(pairs))
log.LogFields(otlog.Error(fmt.Errorf("wrong number of samples")))
log.Error(fmt.Errorf("wrong number of samples"))
return false
}
}
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/spanlogger/spanlogger.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ func (s *SpanLogger) Log(kvps ...interface{}) error {
return nil
}

// Error sets error flag and logs the error, if non-nil. Returns the err passed in.
// Error sets error flag and logs the error on the span, if non-nil. Returns the err passed in.
func (s *SpanLogger) Error(err error) error {
if err == nil {
return nil
Expand Down