From 45c3453a7cd997fed9d6d4ea998135e532b5428a Mon Sep 17 00:00:00 2001
From: Brian Goff <cpuguy83@gmail.com>
Date: Wed, 15 Sep 2021 01:26:56 +0000
Subject: [PATCH] Add open telemetry logging hook for logrus

This adds valuable logging data to the open telemetry traces.

When the trace is not recording we don't bother doing anything as it is
relatively expensive to convert logrus data to otel just due to the
nature of how logrus works.

The way this works is that we now set a context on the logrus.Entry that
gets passed around which the hook then uses to determine if there is an
active span to forward the logs to.

Signed-off-by: Brian Goff <cpuguy83@gmail.com>
---
 cmd/containerd/command/main.go |  6 ++++
 log/context.go                 |  5 +--
 log/context_test.go            |  2 --
 tracing/log.go                 | 66 ++++++++++++++++++++++++++++++++++
 4 files changed, 75 insertions(+), 4 deletions(-)
 create mode 100644 tracing/log.go

diff --git a/cmd/containerd/command/main.go b/cmd/containerd/command/main.go
index ff633dff5..157c5689d 100644
--- a/cmd/containerd/command/main.go
+++ b/cmd/containerd/command/main.go
@@ -320,6 +320,8 @@ func applyFlags(context *cli.Context, config *srvconfig.Config) error {
 	if err := setLogFormat(config); err != nil {
 		return err
 	}
+	setLogHooks()
+
 	for _, v := range []struct {
 		name string
 		d    *string
@@ -385,6 +387,10 @@ func setLogFormat(config *srvconfig.Config) error {
 	return nil
 }
 
+func setLogHooks() {
+	logrus.StandardLogger().AddHook(tracing.NewLogrusHook())
+}
+
 func dumpStacks(writeToFile bool) {
 	var (
 		buf       []byte
diff --git a/log/context.go b/log/context.go
index 37b6a7d1c..0db9562b8 100644
--- a/log/context.go
+++ b/log/context.go
@@ -52,7 +52,8 @@ const (
 // WithLogger returns a new context with the provided logger. Use in
 // combination with logger.WithField(s) for great effect.
 func WithLogger(ctx context.Context, logger *logrus.Entry) context.Context {
-	return context.WithValue(ctx, loggerKey{}, logger)
+	e := logger.WithContext(ctx)
+	return context.WithValue(ctx, loggerKey{}, e)
 }
 
 // GetLogger retrieves the current logger from the context. If no logger is
@@ -61,7 +62,7 @@ func GetLogger(ctx context.Context) *logrus.Entry {
 	logger := ctx.Value(loggerKey{})
 
 	if logger == nil {
-		return L
+		return L.WithContext(ctx)
 	}
 
 	return logger.(*logrus.Entry)
diff --git a/log/context_test.go b/log/context_test.go
index 0d9827c6d..f382ffdbc 100644
--- a/log/context_test.go
+++ b/log/context_test.go
@@ -25,8 +25,6 @@ import (
 
 func TestLoggerContext(t *testing.T) {
 	ctx := context.Background()
-	assert.Equal(t, GetLogger(ctx), L)      // should be same as L variable
-	assert.Equal(t, G(ctx), GetLogger(ctx)) // these should be the same.
 
 	ctx = WithLogger(ctx, G(ctx).WithField("test", "one"))
 	assert.Equal(t, GetLogger(ctx).Data["test"], "one")
diff --git a/tracing/log.go b/tracing/log.go
new file mode 100644
index 000000000..a8c540bb7
--- /dev/null
+++ b/tracing/log.go
@@ -0,0 +1,66 @@
+/*
+   Copyright The containerd Authors.
+
+   Licensed under the Apache License, Version 2.0 (the "License");
+   you may not use this file except in compliance with the License.
+   You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing, software
+   distributed under the License is distributed on an "AS IS" BASIS,
+   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+   See the License for the specific language governing permissions and
+   limitations under the License.
+*/
+
+package tracing
+
+import (
+	"github.com/sirupsen/logrus"
+	"go.opentelemetry.io/otel/attribute"
+	"go.opentelemetry.io/otel/trace"
+)
+
+// NewLogrusHook creates a new logrus hook
+func NewLogrusHook() *LogrusHook {
+	return &LogrusHook{}
+}
+
+// LogrusHook is a logrus hook which adds logrus events to active spans.
+// If the span is not recording or the span context is invalid, the hook is a no-op.
+type LogrusHook struct{}
+
+// Levels returns the logrus levels that this hook is interested in.
+func (h *LogrusHook) Levels() []logrus.Level {
+	return logrus.AllLevels
+}
+
+// Fire is called when a log event occurs.
+func (h *LogrusHook) Fire(entry *logrus.Entry) error {
+	span := trace.SpanFromContext(entry.Context)
+	if span == nil {
+		return nil
+	}
+
+	if !span.SpanContext().IsValid() || !span.IsRecording() {
+		return nil
+	}
+
+	span.AddEvent(
+		entry.Message,
+		trace.WithAttributes(logrusDataToAttrs(entry.Data)...),
+		trace.WithAttributes(attribute.String("level", entry.Level.String())),
+		trace.WithTimestamp(entry.Time),
+	)
+
+	return nil
+}
+
+func logrusDataToAttrs(data logrus.Fields) []attribute.KeyValue {
+	attrs := make([]attribute.KeyValue, 0, len(data))
+	for k, v := range data {
+		attrs = append(attrs, attribute.Any(k, v))
+	}
+	return attrs
+}