Skip to content
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

Jump to bottom

PostingsForMatchersCache: don't create new spans, reduce logging verbosity #575

Merged
merged 3 commits into from
Dec 14, 2023
Merged

PostingsForMatchersCache: don't create new spans, reduce logging verbosity #575

Changes from 1 commit
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
f4cd113
PostingsForMatchersCache: don't create new spans, reduce logging verb…
dimitarvdimitrov Dec 12, 2023
f388b77
Fix tests
dimitarvdimitrov Dec 13, 2023
a14f40e
Rephrase return log line
dimitarvdimitrov Dec 13, 2023
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
41 changes: 12 additions & 29 deletions tsdb/postings_for_matchers_cache.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package tsdb
import (
"container/list"
"context"
"fmt"
"strings"
"sync"
"time"
Expand Down Expand Up @@ -87,12 +88,13 @@ type PostingsForMatchersCache struct {
}

func (c *PostingsForMatchersCache) PostingsForMatchers(ctx context.Context, ix IndexPostingsReader, concurrent bool, ms ...*labels.Matcher) (index.Postings, error) {
ctx, span := c.tracer.Start(ctx, "PostingsForMatchersCache.PostingsForMatchers", trace.WithAttributes(
attribute.Bool("concurrent", concurrent),
c.ttlAttrib,
c.forceAttrib,
))
defer span.End()
span := trace.SpanFromContext(ctx)
defer func(startTime time.Time) {
span.AddEvent(
"returned postings",
trace.WithAttributes(attribute.Bool("concurrent", concurrent), c.ttlAttrib, c.forceAttrib, attribute.Stringer("duration", time.Since(startTime))),
)
dimitarvdimitrov marked this conversation as resolved.
Show resolved Hide resolved
}(time.Now())

if !concurrent && !c.force {
span.AddEvent("cache not used")
Expand Down Expand Up @@ -122,30 +124,18 @@ type postingsForMatcherPromise struct {
}

func (p *postingsForMatcherPromise) result(ctx context.Context) (index.Postings, error) {
span := trace.SpanFromContext(ctx)

select {
case <-ctx.Done():
span.AddEvent("interrupting wait on postingsForMatchers promise due to context error", trace.WithAttributes(
attribute.String("err", ctx.Err().Error()),
))
return nil, ctx.Err()
return nil, fmt.Errorf("interrupting wait on postingsForMatchers promise due to context error: %w", ctx.Err())
case <-p.done:
// Checking context error is necessary for deterministic tests,
// as channel selection order is random
if ctx.Err() != nil {
span.AddEvent("completed postingsForMatchers promise, but context has error", trace.WithAttributes(
attribute.String("err", ctx.Err().Error()),
))
return nil, ctx.Err()
return nil, fmt.Errorf("completed postingsForMatchers promise, but context has error: %w", ctx.Err())
}
if p.err != nil {
span.AddEvent("postingsForMatchers promise completed with error", trace.WithAttributes(
attribute.String("err", p.err.Error()),
))
return nil, p.err
return nil, fmt.Errorf("postingsForMatchers promise completed with error: %w", p.err)
}
span.AddEvent("postingsForMatchers promise completed successfully")
Comment on lines -129 to -148
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

adding events means that the error will be duplicated with the RecordError call in PostingsForMatchers. It's also more expensive.

"postingsForMatchers promise completed successfully" should be accounted for in "returned postings"

return p.cloner.Clone(), nil
}
}
Expand All @@ -168,7 +158,7 @@ func (c *PostingsForMatchersCache) postingsForMatchersPromise(ctx context.Contex
return oldPromise.(*postingsForMatcherPromise).result
}

span.AddEvent("no postingsForMatchers promise in cache, executing query")
span.AddEvent("no postingsForMatchers promise in cache, executing query", trace.WithAttributes(attribute.String("cache_key", key)))

// promise was stored, close its channel after fulfilment
defer close(promise.done)
Expand All @@ -178,15 +168,8 @@ func (c *PostingsForMatchersCache) postingsForMatchersPromise(ctx context.Contex
// FIXME: do we need to cancel the call to postingsForMatchers if all the callers waiting for the result have
// cancelled their context?
if postings, err := c.postingsForMatchers(context.Background(), ix, ms...); err != nil {
span.AddEvent("postingsForMatchers failed", trace.WithAttributes(
attribute.String("cache_key", key),
attribute.String("err", err.Error()),
))
Comment on lines -181 to -184
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

removed because this should be accounted for in the RecordError calls in PostingsForMatchers

promise.err = err
} else {
span.AddEvent("postingsForMatchers succeeded", trace.WithAttributes(
attribute.String("cache_key", key),
))
Comment on lines -187 to -189
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

removed this event because it should be accounted for in the "returned postings" log line

promise.cloner = index.NewPostingsCloner(postings)
}

Expand Down
Loading