Restore baggage support in HotROD 🚗

examples/hotrod/cmd/customer.go

@@ -46,5 +46,4 @@ var customerCmd = &cobra.Command{
 
 func init() {
 	RootCmd.AddCommand(customerCmd)
-
 }

examples/hotrod/cmd/driver.go

@@ -46,5 +46,4 @@ var driverCmd = &cobra.Command{
 
 func init() {
 	RootCmd.AddCommand(driverCmd)
-
 }

examples/hotrod/cmd/frontend.go

@@ -56,5 +56,4 @@ var options frontend.ConfigOptions
 
 func init() {
 	RootCmd.AddCommand(frontendCmd)
-
 }

examples/hotrod/cmd/root.go

@@ -36,6 +36,7 @@ var (
 	logger         *zap.Logger
 	metricsFactory metrics.Factory
 	otelExporter   string // jaeger, otlp, stdout
+	verbose        bool
 
 	fixDBConnDelay         time.Duration
 	fixDBConnDisableMutex  bool
@@ -84,17 +85,28 @@ func init() {
 	RootCmd.PersistentFlags().StringVarP(&basepath, "basepath", "b", "", `Basepath for frontend service(default "/")`)
 	RootCmd.PersistentFlags().StringVarP(&jaegerUI, "jaeger-ui", "j", "http://localhost:16686", "Address of Jaeger UI to create [find trace] links")
 
-	rand.Seed(int64(time.Now().Nanosecond()))
-	logger, _ = zap.NewDevelopment(
-		zap.AddStacktrace(zapcore.FatalLevel),
-		zap.AddCallerSkip(1),
-	)
-	jaegerclientenv2otel.MapJaegerToOtelEnvVars(logger)
+	RootCmd.PersistentFlags().BoolVarP(&verbose, "verbose", "v", false, "Enables debug logging")
+
 	cobra.OnInitialize(onInitialize)
 }
 
 // onInitialize is called before the command is executed.
 func onInitialize() {
+	rand.Seed(int64(time.Now().Nanosecond()))
+
+	zapOptions := []zap.Option{
+		zap.AddStacktrace(zapcore.FatalLevel),
+		zap.AddCallerSkip(1),
+	}
+	if !verbose {
+		zapOptions = append(zapOptions,
+			zap.IncreaseLevel(zap.LevelEnablerFunc(func(l zapcore.Level) bool { return l != zapcore.DebugLevel })),
+		)
+	}
+	logger, _ = zap.NewDevelopment(zapOptions...)
+
+	jaegerclientenv2otel.MapJaegerToOtelEnvVars(logger)
+
 	switch metricsBackend {
 	case "expvar":
 		metricsFactory = expvar.NewFactory(10) // 10 buckets for histograms

examples/hotrod/cmd/route.go

@@ -46,5 +46,4 @@ var routeCmd = &cobra.Command{
 
 func init() {
 	RootCmd.AddCommand(routeCmd)
-
 }

examples/hotrod/pkg/log/factory.go

@@ -37,7 +37,7 @@ func NewFactory(logger *zap.Logger) Factory {
 
 // Bg creates a context-unaware logger.
 func (b Factory) Bg() Logger {
-	return logger(b)
+	return wrapper(b)
 }
 
 // For returns a context-aware Logger. If the context

examples/hotrod/pkg/log/logger.go

@@ -22,33 +22,39 @@ import (
 
 // Logger is a simplified abstraction of the zap.Logger
 type Logger interface {
+	Debug(msg string, fields ...zapcore.Field)
 	Info(msg string, fields ...zapcore.Field)
 	Error(msg string, fields ...zapcore.Field)
 	Fatal(msg string, fields ...zapcore.Field)
 	With(fields ...zapcore.Field) Logger
 }
 
-// logger delegates all calls to the underlying zap.Logger
-type logger struct {
+// wrapper delegates all calls to the underlying zap.Logger
+type wrapper struct {
 	logger *zap.Logger
 }
 
+// Debug logs an debug msg with fields
+func (l wrapper) Debug(msg string, fields ...zapcore.Field) {
+	l.logger.Debug(msg, fields...)
+}
+
 // Info logs an info msg with fields
-func (l logger) Info(msg string, fields ...zapcore.Field) {
+func (l wrapper) Info(msg string, fields ...zapcore.Field) {
 	l.logger.Info(msg, fields...)
 }
 
 // Error logs an error msg with fields
-func (l logger) Error(msg string, fields ...zapcore.Field) {
+func (l wrapper) Error(msg string, fields ...zapcore.Field) {
 	l.logger.Error(msg, fields...)
 }
 
 // Fatal logs a fatal error msg with fields
-func (l logger) Fatal(msg string, fields ...zapcore.Field) {
+func (l wrapper) Fatal(msg string, fields ...zapcore.Field) {
 	l.logger.Fatal(msg, fields...)
 }
 
 // With creates a child logger, and optionally adds some context fields to that logger.
-func (l logger) With(fields ...zapcore.Field) Logger {
-	return logger{logger: l.logger.With(fields...)}
+func (l wrapper) With(fields ...zapcore.Field) Logger {
+	return wrapper{logger: l.logger.With(fields...)}
 }

examples/hotrod/pkg/log/spanlogger.go

@@ -31,6 +31,11 @@ type spanLogger struct {
 	spanFields []zapcore.Field
 }
 
+func (sl spanLogger) Debug(msg string, fields ...zapcore.Field) {
+	sl.logToSpan("Debug", msg, fields...)
+	sl.logger.Debug(msg, append(sl.spanFields, fields...)...)
+}
+
 func (sl spanLogger) Info(msg string, fields ...zapcore.Field) {
 	sl.logToSpan("info", msg, fields...)
 	sl.logger.Info(msg, append(sl.spanFields, fields...)...)

examples/hotrod/pkg/tracing/init.go

@@ -44,14 +44,18 @@ var once sync.Once
 // to return an OpenTracing-compatible tracer.
 func Init(serviceName string, exporterType string, metricsFactory metrics.Factory, logger log.Factory) opentracing.Tracer {
 	once.Do(func() {
-		otel.SetTextMapPropagator(propagation.TraceContext{})
+		otel.SetTextMapPropagator(
+			propagation.NewCompositeTextMapPropagator(
+				propagation.TraceContext{},
+				propagation.Baggage{},
+			))
 	})
 
 	exp, err := createOtelExporter(exporterType)
 	if err != nil {
 		logger.Bg().Fatal("cannot create exporter", zap.String("exporterType", exporterType), zap.Error(err))
 	}
-	logger.Bg().Info("using " + exporterType + " trace exporter")
+	logger.Bg().Debug("using " + exporterType + " trace exporter")
 
 	rpcmetricsObserver := rpcmetrics.NewObserver(metricsFactory, rpcmetrics.DefaultNameNormalizer)
 
@@ -64,7 +68,7 @@ func Init(serviceName string, exporterType string, metricsFactory metrics.Factor
 		)),
 	)
 	otTracer, _ := otbridge.NewTracerPair(tp.Tracer(""))
-	logger.Bg().Info("created OTEL->OT brige", zap.String("service-name", serviceName))
+	logger.Bg().Debug("created OTEL->OT brige", zap.String("service-name", serviceName))
 	return otTracer
 }
 

examples/hotrod/pkg/tracing/mux.go

@@ -20,34 +20,72 @@ import (
 
 	"github.com/opentracing-contrib/go-stdlib/nethttp"
 	"github.com/opentracing/opentracing-go"
+	"go.opentelemetry.io/otel/baggage"
+	"go.opentelemetry.io/otel/propagation"
+	"go.uber.org/zap"
+
+	"github.com/jaegertracing/jaeger/examples/hotrod/pkg/log"
 )
 
 // NewServeMux creates a new TracedServeMux.
-func NewServeMux(tracer opentracing.Tracer) *TracedServeMux {
+func NewServeMux(copyBaggage bool, tracer opentracing.Tracer, logger log.Factory) *TracedServeMux {
 	return &TracedServeMux{
-		mux:    http.NewServeMux(),
-		tracer: tracer,
+		mux:         http.NewServeMux(),
+		copyBaggage: copyBaggage,
+		tracer:      tracer,
+		logger:      logger,
 	}
 }
 
 // TracedServeMux is a wrapper around http.ServeMux that instruments handlers for tracing.
 type TracedServeMux struct {
-	mux    *http.ServeMux
-	tracer opentracing.Tracer
+	mux         *http.ServeMux
+	copyBaggage bool
+	tracer      opentracing.Tracer
+	logger      log.Factory
 }
 
-// Handle implements http.ServeMux#Handle
+// Handle implements http.ServeMux#Handle, which is used to register new handler.
 func (tm *TracedServeMux) Handle(pattern string, handler http.Handler) {
+	tm.logger.Bg().Debug("registering traced handler", zap.String("endpoint", pattern))
+
 	middleware := nethttp.Middleware(
 		tm.tracer,
 		handler,
 		nethttp.OperationNameFunc(func(r *http.Request) string {
 			return "HTTP " + r.Method + " " + pattern
-		}))
-	tm.mux.Handle(pattern, middleware)
+		}),
+		// Jaeger SDK was able to accept `jaeger-baggage` header even for requests without am active trace.
+		// OTEL Bridge does not support that, so we use Baggage propagator to manually extract the baggage
+		// into Context (in otelBaggageExtractor handler below), and once the Bridge creates a Span,
+		// we use this SpanObserver to copy OTEL baggage from Context into the Span.
+		nethttp.MWSpanObserver(func(span opentracing.Span, r *http.Request) {
+			if !tm.copyBaggage {
+				return
+			}
+			bag := baggage.FromContext(r.Context())
+			for _, m := range bag.Members() {
+				if b := span.BaggageItem(m.Key()); b == "" {
+					span.SetBaggageItem(m.Key(), m.Value())
+				}
+			}
+		}),
+	)
+	tm.mux.Handle(pattern, otelBaggageExtractor(middleware))
 }
 
-// ServeHTTP implements http.ServeMux#ServeHTTP
+// ServeHTTP implements http.ServeMux#ServeHTTP.
 func (tm *TracedServeMux) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	tm.mux.ServeHTTP(w, r)
 }
+
+// Used with nethttp.MWSpanObserver above.
+func otelBaggageExtractor(next http.Handler) http.Handler {
+	propagator := propagation.Baggage{}
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		carrier := propagation.HeaderCarrier(r.Header)
+		ctx := propagator.Extract(r.Context(), carrier)
+		r = r.WithContext(ctx)
+		next.ServeHTTP(w, r)
+	})
+}

examples/hotrod/services/customer/client.go

@@ -54,7 +54,6 @@ func (c *Client) Get(ctx context.Context, customerID string) (*Customer, error)
 	c.logger.For(ctx).Info("Getting customer", zap.String("customer_id", customerID))
 
 	url := fmt.Sprintf("http://"+c.hostPort+"/customer?customer=%s", customerID)
-	fmt.Println(url)
 	var customer Customer
 	if err := c.client.GetJSON(ctx, "/customer", url, &customer); err != nil {
 		return nil, err

examples/hotrod/services/customer/server.go

@@ -57,7 +57,7 @@ func (s *Server) Run() error {
 }
 
 func (s *Server) createServeMux() http.Handler {
-	mux := tracing.NewServeMux(s.tracer)
+	mux := tracing.NewServeMux(false, s.tracer, s.logger)
 	mux.Handle("/customer", http.HandlerFunc(s.customer))
 	return mux
 }

examples/hotrod/services/driver/server.go

@@ -43,10 +43,10 @@ var _ DriverServiceServer = (*Server)(nil)
 // NewServer creates a new driver.Server
 func NewServer(hostPort string, otelExporter string, metricsFactory metrics.Factory, logger log.Factory) *Server {
 	tracer := tracing.Init("driver", otelExporter, metricsFactory, logger)
-	server := grpc.NewServer(grpc.UnaryInterceptor(
-		otgrpc.OpenTracingServerInterceptor(tracer)),
-		grpc.StreamInterceptor(
-			otgrpc.OpenTracingStreamServerInterceptor(tracer)))
+	server := grpc.NewServer(
+		grpc.UnaryInterceptor(otgrpc.OpenTracingServerInterceptor(tracer)),
+		grpc.StreamInterceptor(otgrpc.OpenTracingStreamServerInterceptor(tracer)),
+	)
 	return &Server{
 		hostPort: hostPort,
 		tracer:   tracer,

examples/hotrod/services/frontend/server.go

@@ -76,7 +76,7 @@ func (s *Server) Run() error {
 }
 
 func (s *Server) createServeMux() http.Handler {
-	mux := tracing.NewServeMux(s.tracer)
+	mux := tracing.NewServeMux(true, s.tracer, s.logger)
 	p := path.Join("/", s.basepath)
 	mux.Handle(p, http.StripPrefix(p, http.FileServer(s.assetFS)))
 	mux.Handle(path.Join(p, "/dispatch"), http.HandlerFunc(s.dispatch))

examples/hotrod/services/frontend/web_assets/index.html

@@ -69,7 +69,7 @@ <h4>🚗 <em>Rides On Demand</em> 🚗</h4>
   var freshCar = $($("#hotrod-log").prepend('<div class="fresh-car"><em>Dispatching a car...[req: '+requestID+']</em></div>').children()[0]);
   var customer = evt.target.dataset.customer;
   var headers = {
-      'jaeger-baggage': 'session=' + clientUUID + ', request=' + requestID
+      'baggage': 'session=' + clientUUID + ', request=' + requestID
   };
   console.log(headers);
   var before = Date.now();

examples/hotrod/services/route/server.go

@@ -59,7 +59,7 @@ func (s *Server) Run() error {
 }
 
 func (s *Server) createServeMux() http.Handler {
-	mux := tracing.NewServeMux(s.tracer)
+	mux := tracing.NewServeMux(false, s.tracer, s.logger)
 	mux.Handle("/route", http.HandlerFunc(s.route))
 	mux.Handle("/debug/vars", expvar.Handler()) // expvar
 	mux.Handle("/metrics", promhttp.Handler())  // Prometheus