diff --git a/examples/hotrod/cmd/customer.go b/examples/hotrod/cmd/customer.go index 56f77bfec44..9952b2ce57a 100644 --- a/examples/hotrod/cmd/customer.go +++ b/examples/hotrod/cmd/customer.go @@ -46,5 +46,4 @@ var customerCmd = &cobra.Command{ func init() { RootCmd.AddCommand(customerCmd) - } diff --git a/examples/hotrod/cmd/driver.go b/examples/hotrod/cmd/driver.go index ac1bf5ae65a..5ff98d85560 100644 --- a/examples/hotrod/cmd/driver.go +++ b/examples/hotrod/cmd/driver.go @@ -46,5 +46,4 @@ var driverCmd = &cobra.Command{ func init() { RootCmd.AddCommand(driverCmd) - } diff --git a/examples/hotrod/cmd/frontend.go b/examples/hotrod/cmd/frontend.go index edf44501f64..e1eedc65c14 100644 --- a/examples/hotrod/cmd/frontend.go +++ b/examples/hotrod/cmd/frontend.go @@ -56,5 +56,4 @@ var options frontend.ConfigOptions func init() { RootCmd.AddCommand(frontendCmd) - } diff --git a/examples/hotrod/cmd/root.go b/examples/hotrod/cmd/root.go index c76fc785812..e3be64446e7 100644 --- a/examples/hotrod/cmd/root.go +++ b/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 diff --git a/examples/hotrod/cmd/route.go b/examples/hotrod/cmd/route.go index ce54159f17c..191bd96c556 100644 --- a/examples/hotrod/cmd/route.go +++ b/examples/hotrod/cmd/route.go @@ -46,5 +46,4 @@ var routeCmd = &cobra.Command{ func init() { RootCmd.AddCommand(routeCmd) - } diff --git a/examples/hotrod/pkg/log/factory.go b/examples/hotrod/pkg/log/factory.go index 2c85af90c5e..32ae2d818fb 100644 --- a/examples/hotrod/pkg/log/factory.go +++ b/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 diff --git a/examples/hotrod/pkg/log/logger.go b/examples/hotrod/pkg/log/logger.go index 933bdb3d2dd..b81c18a0d30 100644 --- a/examples/hotrod/pkg/log/logger.go +++ b/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...)} } diff --git a/examples/hotrod/pkg/log/spanlogger.go b/examples/hotrod/pkg/log/spanlogger.go index a5ab6f7de82..dd143d19dbd 100644 --- a/examples/hotrod/pkg/log/spanlogger.go +++ b/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...)...) diff --git a/examples/hotrod/pkg/tracing/init.go b/examples/hotrod/pkg/tracing/init.go index eb201e9d6d1..b21b0b06865 100644 --- a/examples/hotrod/pkg/tracing/init.go +++ b/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 } diff --git a/examples/hotrod/pkg/tracing/mux.go b/examples/hotrod/pkg/tracing/mux.go index 260010a6b25..a9102f2ccb4 100644 --- a/examples/hotrod/pkg/tracing/mux.go +++ b/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) + }) +} diff --git a/examples/hotrod/services/customer/client.go b/examples/hotrod/services/customer/client.go index 5d971a64f93..f9595289c44 100644 --- a/examples/hotrod/services/customer/client.go +++ b/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 diff --git a/examples/hotrod/services/customer/server.go b/examples/hotrod/services/customer/server.go index f35a15c36a6..7cbe0e6da4c 100644 --- a/examples/hotrod/services/customer/server.go +++ b/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 } diff --git a/examples/hotrod/services/driver/server.go b/examples/hotrod/services/driver/server.go index da630555df8..e1d1aa3975b 100644 --- a/examples/hotrod/services/driver/server.go +++ b/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, diff --git a/examples/hotrod/services/frontend/server.go b/examples/hotrod/services/frontend/server.go index e47a5615db4..d4d028f1fc4 100644 --- a/examples/hotrod/services/frontend/server.go +++ b/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)) diff --git a/examples/hotrod/services/frontend/web_assets/index.html b/examples/hotrod/services/frontend/web_assets/index.html index d8bf28b85d8..e55b015fa9a 100644 --- a/examples/hotrod/services/frontend/web_assets/index.html +++ b/examples/hotrod/services/frontend/web_assets/index.html @@ -69,7 +69,7 @@

🚗 Rides On Demand 🚗

var freshCar = $($("#hotrod-log").prepend('
Dispatching a car...[req: '+requestID+']
').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(); diff --git a/examples/hotrod/services/route/server.go b/examples/hotrod/services/route/server.go index 389f2470dc0..b93662b84f0 100644 --- a/examples/hotrod/services/route/server.go +++ b/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