Skip to content

Commit

Permalink
Add trace details to every log
Browse files Browse the repository at this point in the history
This will make it easier to correlate logs with tracing.
  • Loading branch information
VoyTechnology committed Sep 16, 2023
1 parent 62fc742 commit d2b11a4
Show file tree
Hide file tree
Showing 2 changed files with 56 additions and 5 deletions.
8 changes: 7 additions & 1 deletion internal/cmd/saferplace/dependencies.go
Original file line number Diff line number Diff line change
Expand Up @@ -66,9 +66,9 @@ func StringsToDependencies(ss []string) []Dependency {

type dependencies struct {
// always created dependencies
logger log.Logger
tracing trace.TracerProvider
metrics *prometheus.Registry
logger log.Logger

// dynamically created dependencies
database database.Database
Expand Down Expand Up @@ -96,6 +96,12 @@ func createDependencies(ctx context.Context, cfg *config.Config, components []Co
mc = append(mc, tracingCloser)
deps.tracing = tracing

deps.logger.Debug(ctx, "tracing initialized",
slog.Bool("enabled", cfg.Tracing.Enabled),
slog.String("endpoint", cfg.Tracing.Endpoint),
slog.Float64("sampling_ratio", cfg.Tracing.SamplingRatio),
)

deps.logger.Debug(ctx, "initializing dependencies",
slog.Any("components", components),
slog.Any("dependencies", wantedDependencies),
Expand Down
53 changes: 49 additions & 4 deletions internal/log/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,8 @@ import (
"log/slog"
"strings"
"time"

"go.opentelemetry.io/otel/trace"
)

// handler is a new handler with a more human readable output which takes less space.
Expand All @@ -32,16 +34,59 @@ func NewHandler(out io.Writer, level slog.Level) *handler {
}

func (h *handler) Handle(ctx context.Context, r slog.Record) error {
kvs := make([]string, 0, r.NumAttrs())
builder := new(strings.Builder)
if !r.Time.IsZero() {
builder.WriteString(r.Time.Format(time.RFC3339Nano) + " ")
}
builder.WriteString(r.Level.String() + "\t" + r.Message + "\t")
r.Attrs(func(a slog.Attr) bool {
kvs = append(kvs, strings.Join(append(h.groups, a.Key), ".")+"="+a.Value.String())
h.appendAttr(builder, a)
return true
})
fmt.Fprintf(h.out, "%s %s\t%s\t%s\n",
r.Time.Format(time.RFC3339Nano), r.Level, r.Message, strings.Join(kvs, " "))

extraAttr := h.attrs[:]
// Add the tracing information if available.
span := trace.SpanFromContext(ctx)
if traceID := span.SpanContext().TraceID(); traceID.IsValid() {
extraAttr = append(extraAttr,
slog.String("trace_id", traceID.String()),
slog.String("span_id", span.SpanContext().SpanID().String()),
)
}

for _, attr := range extraAttr {
h.appendAttr(builder, attr)
}

fmt.Fprintln(h.out, builder.String())
return nil
}

func (h *handler) appendAttr(builder *strings.Builder, a slog.Attr) {
a.Value = a.Value.Resolve()
// ignore empty attr
if a.Equal(slog.Attr{}) {
return
}
switch a.Value.Kind() {
case slog.KindString:
builder.WriteString(fmt.Sprintf("%s=%q", a.Key, a.Value.String()) + " ")
case slog.KindTime:
builder.WriteString(a.Key + "=" + a.Value.Time().Format(time.RFC3339Nano) + " ")
case slog.KindGroup:
attrs := a.Value.Group()
if len(attrs) == 0 {
return
}
for _, ga := range attrs {
ga.Key = a.Key + "." + ga.Key
h.appendAttr(builder, ga)
}
default:
builder.WriteString(fmt.Sprintf("%s=%s", a.Key, a.Value.String()) + " ")
}
}

func (h *handler) clone() *handler {
c := *h
return &c
Expand Down

0 comments on commit d2b11a4

Please sign in to comment.