Skip to content

Commit

Permalink
Convert backend helpers to use slog
Browse files Browse the repository at this point in the history
  • Loading branch information
rosstimothy committed Sep 23, 2024
1 parent b5d8f36 commit 8f5938e
Show file tree
Hide file tree
Showing 4 changed files with 33 additions and 31 deletions.
24 changes: 12 additions & 12 deletions lib/backend/buffer.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,17 +22,18 @@ import (
"bytes"
"context"
"fmt"
"log/slog"
"sort"
"sync"
"time"

radix "github.com/armon/go-radix"
"github.com/gravitational/trace"
"github.com/jonboulle/clockwork"
log "github.com/sirupsen/logrus"

"github.com/gravitational/teleport"
"github.com/gravitational/teleport/api/types"
logutils "github.com/gravitational/teleport/lib/utils/log"
)

type bufferConfig struct {
Expand Down Expand Up @@ -85,7 +86,7 @@ func BufferClock(c clockwork.Clock) BufferOption {
// of predefined size, that is capable of fan-out of the backend events.
type CircularBuffer struct {
sync.Mutex
*log.Entry
logger *slog.Logger
cfg bufferConfig
init, closed bool
watchers *watcherTree
Expand All @@ -103,9 +104,7 @@ func NewCircularBuffer(opts ...BufferOption) *CircularBuffer {
opt(&cfg)
}
return &CircularBuffer{
Entry: log.WithFields(log.Fields{
teleport.ComponentKey: teleport.ComponentBuffer,
}),
logger: slog.With(teleport.ComponentKey, teleport.ComponentBuffer),
cfg: cfg,
watchers: newWatcherTree(),
}
Expand Down Expand Up @@ -157,7 +156,7 @@ func (c *CircularBuffer) SetInit() {
})

for _, watcher := range watchersToDelete {
c.Warningf("Closing %v, failed to send init event.", watcher)
c.logger.WarnContext(context.Background(), "Closing watcher, failed to send init event.", "watcher", logutils.StringerAttr(watcher))
watcher.closeWatcher()
c.watchers.rm(watcher)
}
Expand Down Expand Up @@ -213,7 +212,7 @@ func (c *CircularBuffer) fanOutEvent(r Event) {
})

for _, watcher := range watchersToDelete {
c.Warningf("Closing %v, buffer overflow at %v (backlog=%v).", watcher, len(watcher.eventsC), watcher.backlogLen())
c.logger.WarnContext(context.Background(), "Closing watcher, buffer overflow", "watcher", logutils.StringerAttr(watcher), "events", len(watcher.eventsC), "backlog", watcher.backlogLen())
watcher.closeWatcher()
c.watchers.rm(watcher)
}
Expand Down Expand Up @@ -275,10 +274,10 @@ func (c *CircularBuffer) NewWatcher(ctx context.Context, watch Watch) (Watcher,
cancel: cancel,
capacity: watch.QueueSize,
}
c.Debugf("Add %v.", w)
c.logger.DebugContext(ctx, "Adding wacther", "watcher", logutils.StringerAttr(w))
if c.init {
if ok := w.init(); !ok {
c.Warningf("Closing %v, failed to send init event.", w)
c.logger.WarnContext(ctx, "Closing watcher, failed to send init event.", "watcher", logutils.StringerAttr(w))
return nil, trace.BadParameter("failed to send init event")
}
}
Expand All @@ -287,16 +286,17 @@ func (c *CircularBuffer) NewWatcher(ctx context.Context, watch Watch) (Watcher,
}

func (c *CircularBuffer) removeWatcherWithLock(watcher *BufferWatcher) {
ctx := context.Background()
c.Lock()
defer c.Unlock()
if watcher == nil {
c.Warningf("Internal logic error: %v.", trace.DebugReport(trace.BadParameter("empty watcher")))
c.logger.WarnContext(ctx, "Internal logic error, empty watcher")
return
}
c.Debugf("Removing watcher %v (%p) via external close.", watcher.Name, watcher)
c.logger.DebugContext(ctx, "Removing watcher via external close.", "watcher", logutils.StringerAttr(watcher))
found := c.watchers.rm(watcher)
if !found {
c.Debugf("Could not find watcher %v.", watcher.Name)
c.logger.DebugContext(ctx, "Could not find watcher", "watcher", watcher.Name)
}
}

Expand Down
6 changes: 4 additions & 2 deletions lib/backend/helpers.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,11 +21,13 @@ package backend
import (
"bytes"
"context"
"log/slog"
"time"

"github.com/google/uuid"
"github.com/gravitational/trace"
log "github.com/sirupsen/logrus"

logutils "github.com/gravitational/teleport/lib/utils/log"
)

const (
Expand Down Expand Up @@ -209,7 +211,7 @@ func RunWhileLocked(ctx context.Context, cfg RunWhileLockedConfig, fn func(conte
case <-cfg.Backend.Clock().After(refreshAfter):
if err := lock.resetTTL(ctx, cfg.Backend); err != nil {
cancelFunction()
log.Errorf("%v", err)
slog.ErrorContext(ctx, "failed to reset lock ttl", "error", err, "lock", logutils.StringerAttr(lock.key))
return
}
case <-stopRefresh:
Expand Down
31 changes: 15 additions & 16 deletions lib/backend/report.go
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,6 @@ import (
lru "github.com/hashicorp/golang-lru/v2"
"github.com/jonboulle/clockwork"
"github.com/prometheus/client_golang/prometheus"
log "github.com/sirupsen/logrus"
"go.opentelemetry.io/otel/attribute"
oteltrace "go.opentelemetry.io/otel/trace"
"golang.org/x/time/rate"
Expand Down Expand Up @@ -147,7 +146,7 @@ func (s *Reporter) GetRange(ctx context.Context, startKey, endKey Key, limit int
} else {
reads.WithLabelValues(s.Component).Add(float64(len(res.Items)))
}
s.trackRequest(types.OpGet, startKey, endKey)
s.trackRequest(ctx, types.OpGet, startKey, endKey)
end := s.Clock().Now()
if d := end.Sub(start); d > time.Second*3 {
if s.slowRangeLogLimiter.AllowN(end, 1) {
Expand Down Expand Up @@ -181,7 +180,7 @@ func (s *Reporter) Create(ctx context.Context, i Item) (*Lease, error) {
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpPut, i.Key, nil)
s.trackRequest(ctx, types.OpPut, i.Key, nil)
return lease, err
}

Expand All @@ -207,7 +206,7 @@ func (s *Reporter) Put(ctx context.Context, i Item) (*Lease, error) {
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpPut, i.Key, nil)
s.trackRequest(ctx, types.OpPut, i.Key, nil)
return lease, err
}

Expand Down Expand Up @@ -235,7 +234,7 @@ func (s *Reporter) Update(ctx context.Context, i Item) (*Lease, error) {
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpPut, i.Key, nil)
s.trackRequest(ctx, types.OpPut, i.Key, nil)
return lease, err
}

Expand Down Expand Up @@ -263,7 +262,7 @@ func (s *Reporter) ConditionalUpdate(ctx context.Context, i Item) (*Lease, error
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpPut, i.Key, nil)
s.trackRequest(ctx, types.OpPut, i.Key, nil)
return lease, err
}

Expand All @@ -286,7 +285,7 @@ func (s *Reporter) Get(ctx context.Context, key Key) (*Item, error) {
if err != nil && !trace.IsNotFound(err) {
readRequestsFailed.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpGet, key, nil)
s.trackRequest(ctx, types.OpGet, key, nil)
return item, err
}

Expand Down Expand Up @@ -314,7 +313,7 @@ func (s *Reporter) CompareAndSwap(ctx context.Context, expected Item, replaceWit
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpPut, expected.Key, nil)
s.trackRequest(ctx, types.OpPut, expected.Key, nil)
return lease, err
}

Expand All @@ -341,7 +340,7 @@ func (s *Reporter) Delete(ctx context.Context, key Key) error {
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpDelete, key, nil)
s.trackRequest(ctx, types.OpDelete, key, nil)
return err
}

Expand Down Expand Up @@ -369,7 +368,7 @@ func (s *Reporter) ConditionalDelete(ctx context.Context, key Key, revision stri
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpDelete, key, nil)
s.trackRequest(ctx, types.OpDelete, key, nil)
return err
}

Expand Down Expand Up @@ -411,10 +410,10 @@ func (s *Reporter) AtomicWrite(ctx context.Context, condacts []ConditionalAction
switch ca.Action.Kind {
case KindPut:
writeTotal++
s.trackRequest(types.OpPut, ca.Key, nil)
s.trackRequest(ctx, types.OpPut, ca.Key, nil)
case KindDelete:
writeTotal++
s.trackRequest(types.OpDelete, ca.Key, nil)
s.trackRequest(ctx, types.OpDelete, ca.Key, nil)
default:
// ignore other variants
}
Expand Down Expand Up @@ -445,7 +444,7 @@ func (s *Reporter) DeleteRange(ctx context.Context, startKey, endKey Key) error
if err != nil && !trace.IsNotFound(err) {
batchWriteRequestsFailed.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpDelete, startKey, endKey)
s.trackRequest(ctx, types.OpDelete, startKey, endKey)
return err
}

Expand Down Expand Up @@ -476,7 +475,7 @@ func (s *Reporter) KeepAlive(ctx context.Context, lease Lease, expires time.Time
} else {
writes.WithLabelValues(s.Component).Inc()
}
s.trackRequest(types.OpPut, lease.Key, nil)
s.trackRequest(ctx, types.OpPut, lease.Key, nil)
return err
}

Expand Down Expand Up @@ -521,7 +520,7 @@ type topRequestsCacheKey struct {
}

// trackRequests tracks top requests, endKey is supplied for ranges
func (s *Reporter) trackRequest(opType types.OpType, key Key, endKey Key) {
func (s *Reporter) trackRequest(ctx context.Context, opType types.OpType, key Key, endKey Key) {
if len(key) == 0 {
return
}
Expand Down Expand Up @@ -551,7 +550,7 @@ func (s *Reporter) trackRequest(opType types.OpType, key Key, endKey Key) {

counter, err := requests.GetMetricWithLabelValues(s.Component, keyLabel, rangeSuffix)
if err != nil {
log.Warningf("Failed to get counter: %v", err)
slog.WarnContext(ctx, "Failed to get prometheus counter", "error", err)
return
}
counter.Inc()
Expand Down
3 changes: 2 additions & 1 deletion lib/backend/report_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
package backend

import (
"context"
"strconv"
"sync/atomic"
"testing"
Expand Down Expand Up @@ -60,7 +61,7 @@ func TestReporterTopRequestsLimit(t *testing.T) {

// Run through 1000 unique keys.
for i := 0; i < 1000; i++ {
r.trackRequest(types.OpGet, []byte(strconv.Itoa(i)), nil)
r.trackRequest(context.Background(), types.OpGet, []byte(strconv.Itoa(i)), nil)
}

// Now the metric should have only 10 of the keys above.
Expand Down

0 comments on commit 8f5938e

Please sign in to comment.