Merge pull request #53 from smallstep/herman/legacy-request-id-interop

Log propagated request ID and allow interoperability with legacy tracing

grpclog/server_logger.go

@@ -16,6 +16,7 @@ import (
 	"google.golang.org/grpc/status"
 
 	"github.com/smallstep/logging"
+	"github.com/smallstep/logging/requestid"
 )
 
 type serverLogger struct {
@@ -50,14 +51,22 @@ func (l *serverLogger) Log(ctx context.Context, fullMethod string, t time.Time,
 	}
 
 	var name, requestID, tracingID string
+
+	// Use (reflected) request ID for logging. It _could_ be empty if it wasn't set
+	// by some (external) middleware, but we stil log the legacy request ID too, so
+	// it shouldn't be too big of an issue.
+	requestID = requestid.FromContext(ctx)
+
 	if s, ok := logging.GetName(ctx); ok {
 		name = s
 	} else {
 		name = l.name
 	}
 	if tp, ok := logging.GetTraceparent(ctx); ok {
-		requestID = tp.TraceID()
 		tracingID = tp.String()
+		if requestID == "" {
+			requestID = tp.TraceID()
+		}
 	}
 
 	fields := []zap.Field{
@@ -119,14 +128,22 @@ func (l *serverLogger) LogStream(ctx context.Context, fullMethod, msg string, ex
 	}
 
 	var name, requestID, tracingID string
+
+	// Use (reflected) request ID for logging. It _could_ be empty if it wasn't set
+	// by some (external) middleware, but we stil log the legacy request ID too, so
+	// it shouldn't be too big of an issue.
+	requestID = requestid.FromContext(ctx)
+
 	if s, ok := logging.GetName(ctx); ok {
 		name = s
 	} else {
 		name = l.name
 	}
 	if tp, ok := logging.GetTraceparent(ctx); ok {
-		requestID = tp.TraceID()
 		tracingID = tp.String()
+		if requestID == "" {
+			requestID = tp.TraceID()
+		}
 	}
 
 	fields := []zap.Field{

httplog/handler.go

@@ -7,6 +7,7 @@ import (
 	"time"
 
 	"github.com/smallstep/logging"
+	"github.com/smallstep/logging/requestid"
 	"go.uber.org/zap"
 )
 
@@ -92,14 +93,22 @@ func (l *LoggerHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 func (l *LoggerHandler) writeEntry(w ResponseLogger, r *http.Request, t time.Time, d time.Duration) {
 	ctx := r.Context()
 	var name, requestID, tracingID string
+
+	// Use (reflected) request ID for logging. It _could_ be empty if it wasn't set
+	// by some (external) middleware, but we stil log the legacy request ID too, so
+	// it shouldn't be too big of an issue.
+	requestID = requestid.FromContext(ctx)
+
 	if s, ok := logging.GetName(ctx); ok {
 		name = s
 	} else {
 		name = l.name
 	}
 	if tp, ok := logging.GetTraceparent(ctx); ok {
-		requestID = tp.TraceID()
 		tracingID = tp.String()
+		if requestID == "" {
+			requestID = tp.TraceID()
+		}
 	}
 
 	// Remote hostname

requestid/requestid.go

@@ -0,0 +1,16 @@
+package requestid
+
+import "context"
+
+type contextKey struct{}
+
+func NewContext(ctx context.Context, requestID string) context.Context {
+	return context.WithValue(ctx, contextKey{}, requestID)
+}
+
+func FromContext(ctx context.Context) string {
+	if v, ok := ctx.Value(contextKey{}).(string); ok {
+		return v
+	}
+	return ""
+}