chore: update how we get request IDs (#313)

* update how we get request IDs

* test that we log properly

* also test that the tracer is injected

Author: rybit

router/router_test.go

@@ -6,6 +6,8 @@ import (
 	"strconv"
 	"testing"
 
+	"github.com/netlify/netlify-commons/testutil"
+	"github.com/netlify/netlify-commons/tracing"
 	"github.com/opentracing/opentracing-go"
 	"github.com/opentracing/opentracing-go/mocktracer"
 	"github.com/sirupsen/logrus"
@@ -79,11 +81,13 @@ func TestTracing(t *testing.T) {
 	}()
 
 	noop := func(w http.ResponseWriter, r *http.Request) error {
+		assert.NotNil(t, tracing.GetTracer(r))
 		w.WriteHeader(http.StatusOK)
 		return nil
 	}
 
-	r := New(logrus.WithField("test", t.Name()), OptEnableTracing("some-service"))
+	tl, logHook := testutil.TestLogger(t)
+	r := New(tl, OptEnableTracing("some-service"))
 
 	r.Method(http.MethodPatch, "/patch", noop)
 	r.Delete("/abc/{def}", noop)
@@ -110,6 +114,7 @@ func TestTracing(t *testing.T) {
 	for name, scene := range scenes {
 		t.Run(name, func(t *testing.T) {
 			mt.Reset()
+			logHook.Reset()
 
 			rec := httptest.NewRecorder()
 			r.ServeHTTP(rec, httptest.NewRequest(scene.method, scene.path, nil))
@@ -121,6 +126,8 @@ func TestTracing(t *testing.T) {
 				assert.Equal(t, scene.resourceName, spans[0].Tag(ext.ResourceName))
 				assert.Equal(t, strconv.Itoa(http.StatusOK), spans[0].Tag(ext.HTTPCode))
 			}
+			// should be a starting and finished request for each request
+			assert.Len(t, logHook.AllEntries(), 2)
 		})
 	}
 }

tracing/context.go

@@ -3,6 +3,8 @@ package tracing
 import (
 	"context"
 	"net/http"
+
+	uuid "github.com/satori/go.uuid"
 )
 
 type contextKey string
@@ -33,7 +35,10 @@ func GetRequestID(r *http.Request) string {
 	if id := GetRequestIDFromContext(r.Context()); id != "" {
 		return id
 	}
-	return r.Header.Get(HeaderRequestUUID)
+	if rid := r.Header.Get(HeaderRequestUUID); rid != "" {
+		return rid
+	}
+	return uuid.NewV4().String()
 }
 
 func GetRequestIDFromContext(ctx context.Context) string {

tracing/logging.go

@@ -8,17 +8,14 @@ import (
 	"github.com/sirupsen/logrus"
 )
 
-const (
-	logKey = contextKey("nf-log-key")
-)
-
-func requestLogger(r *http.Request, log logrus.FieldLogger) (logrus.FieldLogger, string) {
+func RequestLogger(r *http.Request, log logrus.FieldLogger) (logrus.FieldLogger, string) {
 	if r.Header.Get(HeaderNFDebugLogging) != "" {
 		logger := logrus.New()
 		logger.SetLevel(logrus.DebugLevel)
 
 		if entry, ok := log.(*logrus.Entry); ok {
 			log = logger.WithFields(entry.Data)
+			logger.Hooks = entry.Logger.Hooks
 		}
 	}
 

tracing/req_tracer.go

@@ -27,7 +27,7 @@ type RequestTracer struct {
 
 func NewTracer(w http.ResponseWriter, r *http.Request, log logrus.FieldLogger, service, resource string) (http.ResponseWriter, *http.Request, *RequestTracer) {
 	var reqID string
-	log, reqID = requestLogger(r, log)
+	log, reqID = RequestLogger(r, log)
 
 	r, span := WrapWithSpan(r, reqID, service, resource)
 	trackWriter := &trackingWriter{