feat: allow disabling trace logging, while keeping Datadog tracing enabled

router/errors_test.go

@@ -26,6 +26,7 @@ func TestHandleError_ErrorIsNil(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	HandleError(nil, w, r)
@@ -42,6 +43,7 @@ func TestHandleError_ErrorIsNilPointerToTypeHTTPError(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	h := func(_ http.ResponseWriter, _ *http.Request) *HTTPError {
@@ -62,6 +64,7 @@ func TestHandleError_ErrorIsNilInterface(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	h := func(_ http.ResponseWriter, _ *http.Request) error {
@@ -82,6 +85,7 @@ func TestHandleError_StandardError(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	HandleError(errors.New("random error"), w, r)
@@ -100,6 +104,7 @@ func TestHandleError_HTTPError(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	httpErr := &HTTPError{
@@ -131,6 +136,7 @@ func TestHandleError_HttpErrorWithFields(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	httpErr := httpError(http.StatusInternalServerError, http.StatusText(http.StatusInternalServerError))
@@ -161,6 +167,7 @@ func TestHandleError_NoLogForNormalErrors(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	httpErr := BadRequestError("not found yo.")
@@ -194,6 +201,7 @@ func TestHandleError_ErrorIsNilPointerToTypeOtherError(t *testing.T) {
 		logger,
 		"test",
 		"test",
+		true,
 	)
 
 	var oe *OtherError

router/middleware.go

@@ -151,6 +151,6 @@ func TrackAllRequests(log logrus.FieldLogger, service string) Middleware {
 	return MiddlewareFunc(func(w http.ResponseWriter, r *http.Request, next http.Handler) {
 		// This is to maintain some legacy span work. It will cause the APM requests
 		// to show up as the method on the top level
-		tracing.TrackRequest(w, r, log, service, r.Method, next)
+		tracing.TrackRequest(w, r, log, service, r.Method, true, next)
 	})
 }

router/middleware_test.go

@@ -135,6 +135,7 @@ func TestRecoveryInternalTracer(t *testing.T) {
 		logger,
 		t.Name(),
 		"some_resource",
+		true,
 	)
 	mw := Recoverer(logrus.New())
 	handler := mw(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {

router/options.go

@@ -27,6 +27,13 @@ func OptEnableTracing(svcName string) Option {
 	return func(r *chiWrapper) {
 		r.svcName = svcName
 		r.enableTracing = true
+		r.enableTraceLogging = true
+	}
+}
+
+func OptDisableTraceLogging() Option {
+	return func(r *chiWrapper) {
+		r.enableTraceLogging = false
 	}
 }
 

router/router.go

@@ -23,9 +23,10 @@ type chiWrapper struct {
 	healthEndpoint string
 	healthHandler  APIHandler
 
-	enableTracing bool
-	enableCORS    bool
-	enableRecover bool
+	enableTracing      bool
+	enableTraceLogging bool
+	enableCORS         bool
+	enableRecover      bool
 }
 
 // Router wraps the chi router to make it slightly more accessible
@@ -145,7 +146,7 @@ func (r *chiWrapper) ServeHTTP(w http.ResponseWriter, req *http.Request) {
 func (r *chiWrapper) Mount(pattern string, h http.Handler) {
 	if r.enableTracing {
 		h = http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
-			tracing.TrackRequest(w, req, r.rootLogger, r.svcName, pattern, h)
+			tracing.TrackRequest(w, req, r.rootLogger, r.svcName, pattern, r.enableTraceLogging, h)
 		})
 	}
 	r.chi.Mount(pattern, h)
@@ -179,7 +180,7 @@ func (r *chiWrapper) traceRequest(method, pattern string, fn APIHandler) http.Ha
 		}
 
 		return func(w http.ResponseWriter, req *http.Request) {
-			tracing.TrackRequest(w, req, r.rootLogger, r.svcName, resourceName, f)
+			tracing.TrackRequest(w, req, r.rootLogger, r.svcName, resourceName, r.enableTraceLogging, f)
 		}
 	}
 	return f

router/router_test.go

@@ -132,6 +132,50 @@ func TestTracing(t *testing.T) {
 	}
 }
 
+func TestDisableTraceLogging(t *testing.T) {
+	noop := func(w http.ResponseWriter, r *http.Request) error {
+		w.WriteHeader(http.StatusOK)
+		return nil
+	}
+
+	tl, logHook := testutil.TestLogger(t)
+	r := New(tl, OptEnableTracing("some-service"), OptDisableTraceLogging())
+
+	r.Method(http.MethodPatch, "/patch", noop)
+	r.Delete("/abc/{def}", noop)
+	r.Get("/abc/{def}", noop)
+	r.Get("/", noop)
+	r.Post("/def/ghi", noop)
+	r.Put("/asdf/", noop)
+	r.Route("/sub", func(r Router) {
+		r.Get("/path", noop)
+	})
+
+	scenes := map[string]struct {
+		method, path, resourceName string
+	}{
+		"get":          {http.MethodGet, "/abc/def", "GET::abc.def"},
+		"delete":       {http.MethodDelete, "/abc/hfj", "DELETE::abc.def"},
+		"post":         {http.MethodPost, "/def/ghi", "POST::def.ghi"},
+		"put":          {http.MethodPut, "/asdf/", "PUT::asdf"},
+		"patch":        {http.MethodPatch, "/patch", "PATCH::patch"},
+		"subroute":     {http.MethodGet, "/sub/path", "GET::sub.path"},
+		"single_slash": {http.MethodGet, "/", "GET"},
+	}
+
+	for name, scene := range scenes {
+		t.Run(name, func(t *testing.T) {
+			logHook.Reset()
+
+			rec := httptest.NewRecorder()
+			r.ServeHTTP(rec, httptest.NewRequest(scene.method, scene.path, nil))
+			assert.Equal(t, http.StatusOK, rec.Code)
+
+			assert.Len(t, logHook.AllEntries(), 0)
+		})
+	}
+}
+
 func TestVersionHeader(t *testing.T) {
 	scenes := map[string]struct {
 		version  string

server/server.go

@@ -32,7 +32,8 @@ type Server struct {
 }
 
 type RouterConfig struct {
-	DisableTracing bool
+	DisableTracing      bool
+	DisableTraceLogging bool
 }
 
 type Config struct {
@@ -196,6 +197,10 @@ func buildRouter(log logrus.FieldLogger, api APIDefinition, config Config) route
 		opts = append(opts, router.OptEnableTracing(api.Info().Name))
 	}
 
+	if config.Router.DisableTraceLogging {
+		opts = append(opts, router.OptDisableTraceLogging())
+	}
+
 	r := router.New(
 		log,
 		opts...,

tracing/req_tracer.go

@@ -14,6 +14,8 @@ type RequestTracer struct {
 	*trackingWriter
 	logrus.FieldLogger
 
+	enableTraceLogging bool
+
 	RequestID   string
 	finalFields map[string]interface{}
 
@@ -25,7 +27,7 @@ type RequestTracer struct {
 	start       time.Time
 }
 
-func NewTracer(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, service, resource string) (http.ResponseWriter, *http.Request, *RequestTracer) {
+func NewTracer(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, service, resource string, enableTraceLogging bool) (http.ResponseWriter, *http.Request, *RequestTracer) {
 	var reqID string
 	log, reqID = RequestLogger(r, log)
 
@@ -41,11 +43,12 @@ func NewTracer(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, s
 		referrer:    r.Referer(),
 		remoteAddr:  r.RemoteAddr,
 
-		RequestID:      reqID,
-		span:           span,
-		trackingWriter: trackWriter,
-		FieldLogger:    log,
-		finalFields:    make(map[string]interface{}),
+		RequestID:          reqID,
+		span:               span,
+		trackingWriter:     trackWriter,
+		FieldLogger:        log,
+		enableTraceLogging: enableTraceLogging,
+		finalFields:        make(map[string]interface{}),
 	}
 	r = WrapWithTracer(r, rt)
 
@@ -54,34 +57,40 @@ func NewTracer(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, s
 
 func (rt *RequestTracer) Start() {
 	rt.start = time.Now()
-	rt.WithFields(logrus.Fields{
-		"method":      rt.method,
-		"remote_addr": rt.remoteAddr,
-		"referer":     rt.referrer,
-		"url":         rt.originalURL,
-	}).Info("Starting Request")
-}
-
-func (rt *RequestTracer) Finish() {
-	dur := time.Since(rt.start)
 
-	fields := logrus.Fields{}
-	for k, v := range rt.finalFields {
-		fields[k] = v
+	if rt.enableTraceLogging {
+		rt.WithFields(logrus.Fields{
+			"method":      rt.method,
+			"remote_addr": rt.remoteAddr,
+			"referer":     rt.referrer,
+			"url":         rt.originalURL,
+		}).Info("Starting Request")
 	}
+}
 
-	fields["status_code"] = rt.trackingWriter.status
-	fields["rsp_bytes"] = rt.trackingWriter.rspBytes
-	fields["url"] = rt.originalURL
-	fields["method"] = rt.method
-	fields["dur"] = dur.String()
-	fields["dur_ns"] = dur.Nanoseconds()
-
+func (rt *RequestTracer) Finish() {
 	// Setting the status as an int doesn't propogate for use in datadog dashboards,
 	// so we convert to a string.
 	rt.span.SetTag(ext.HTTPCode, strconv.Itoa(rt.trackingWriter.status))
 	rt.span.Finish()
-	rt.WithFields(fields).Info("Completed Request")
+
+	if rt.enableTraceLogging {
+		dur := time.Since(rt.start)
+
+		fields := logrus.Fields{}
+		for k, v := range rt.finalFields {
+			fields[k] = v
+		}
+
+		fields["status_code"] = rt.trackingWriter.status
+		fields["rsp_bytes"] = rt.trackingWriter.rspBytes
+		fields["url"] = rt.originalURL
+		fields["method"] = rt.method
+		fields["dur"] = dur.String()
+		fields["dur_ns"] = dur.Nanoseconds()
+
+		rt.WithFields(fields).Info("Completed Request")
+	}
 }
 
 func (rt *RequestTracer) SetLogField(key string, value interface{}) logrus.FieldLogger {

tracing/req_tracer_test.go

@@ -20,7 +20,7 @@ func TestTracerLogging(t *testing.T) {
 
 	log, hook := logtest.NewNullLogger()
 
-	_, r, rt := NewTracer(rec, req, log, t.Name(), "some_resource")
+	_, r, rt := NewTracer(rec, req, log, t.Name(), "some_resource", true)
 
 	rt.Start()
 	e := hook.LastEntry()
@@ -66,6 +66,19 @@ func TestTracerLogging(t *testing.T) {
 	assert.Equal(t, "line", e.Data["final"])
 }
 
+func TestTracerLoggingIfDisabled(t *testing.T) {
+	rec := httptest.NewRecorder()
+	req := httptest.NewRequest(http.MethodGet, "http://whatever.com/something", nil)
+
+	log, hook := logtest.NewNullLogger()
+
+	_, _, rt := NewTracer(rec, req, log, t.Name(), "some_resource", false)
+
+	rt.Start()
+	rt.Finish()
+	assert.Len(t, hook.Entries, 0)
+}
+
 func TestTracerSpans(t *testing.T) {
 	rec := httptest.NewRecorder()
 	req := httptest.NewRequest(http.MethodGet, "http://whatever.com/something", nil)
@@ -74,7 +87,7 @@ func TestTracerSpans(t *testing.T) {
 
 	mt := mocktracer.New()
 	opentracing.SetGlobalTracer(mt)
-	_, _, rt := NewTracer(rec, req, log, t.Name(), "some_resource")
+	_, _, rt := NewTracer(rec, req, log, t.Name(), "some_resource", true)
 	rt.Start()
 	rt.WriteHeader(http.StatusOK)
 	rt.Finish()

tracing/tracer.go

@@ -11,8 +11,8 @@ import (
 	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/opentracer"
 )
 
-func TrackRequest(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, service, resource string, next http.Handler) {
-	w, r, rt := NewTracer(w, r, log, service, resource)
+func TrackRequest(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, service, resource string, enableTraceLogging bool, next http.Handler) {
+	w, r, rt := NewTracer(w, r, log, service, resource, enableTraceLogging)
 	rt.Start()
 	next.ServeHTTP(w, r)
 	rt.Finish()