[feature] Add a request ID and include it in logs (#1476)

This adds a lightweight form of tracing to GTS. Each incoming request is
assigned a Request ID which we then pass on and log in all our log
lines. Any function that gets called downstream from an HTTP handler
should now emit a requestID=value pair whenever it logs something.

Co-authored-by: kim <grufwub@gmail.com>

3 files changed, 15 insertions, 14 deletions

diff --git a/internal/transport/controller.go b/internal/transport/controller.go
index 6c2aec052..abcccfe1e 100644
--- a/internal/transport/controller.go
+++ b/internal/transport/controller.go
@@ -76,13 +76,13 @@ func NewController(db db.DB, federatingDB federatingdb.DB, clock pub.Clock, clie
 	// Transport cache has TTL=1hr freq=1min
 	c.trspCache.SetTTL(time.Hour, false)
 	if !c.trspCache.Start(time.Minute) {
-		log.Panic("failed to start transport controller cache")
+		log.Panic(nil, "failed to start transport controller cache")
 	}
 
 	// Bad hosts cache has TTL=15min freq=1min
 	c.badHosts.SetTTL(15*time.Minute, false)
 	if !c.badHosts.Start(time.Minute) {
-		log.Panic("failed to start transport controller cache")
+		log.Panic(nil, "failed to start transport controller cache")
 	}
 
 	return c
diff --git a/internal/transport/derefinstance.go b/internal/transport/derefinstance.go
index b8be2f717..e46b52554 100644
--- a/internal/transport/derefinstance.go
+++ b/internal/transport/derefinstance.go
@@ -45,26 +45,26 @@ func (t *transport) DereferenceInstance(ctx context.Context, iri *url.URL) (*gts
 	// This will provide the most complete picture of an instance, and avoid unnecessary api calls.
 	//
 	// This will only work with Mastodon-api compatible instances: Mastodon, some Pleroma instances, GoToSocial.
-	log.Debugf("trying to dereference instance %s by /api/v1/instance", iri.Host)
+	log.Debugf(ctx, "trying to dereference instance %s by /api/v1/instance", iri.Host)
 	i, err = dereferenceByAPIV1Instance(ctx, t, iri)
 	if err == nil {
-		log.Debugf("successfully dereferenced instance using /api/v1/instance")
+		log.Debugf(ctx, "successfully dereferenced instance using /api/v1/instance")
 		return i, nil
 	}
-	log.Debugf("couldn't dereference instance using /api/v1/instance: %s", err)
+	log.Debugf(ctx, "couldn't dereference instance using /api/v1/instance: %s", err)
 
 	// If that doesn't work, try to dereference using /.well-known/nodeinfo.
 	// This will involve two API calls and return less info overall, but should be more widely compatible.
-	log.Debugf("trying to dereference instance %s by /.well-known/nodeinfo", iri.Host)
+	log.Debugf(ctx, "trying to dereference instance %s by /.well-known/nodeinfo", iri.Host)
 	i, err = dereferenceByNodeInfo(ctx, t, iri)
 	if err == nil {
-		log.Debugf("successfully dereferenced instance using /.well-known/nodeinfo")
+		log.Debugf(ctx, "successfully dereferenced instance using /.well-known/nodeinfo")
 		return i, nil
 	}
-	log.Debugf("couldn't dereference instance using /.well-known/nodeinfo: %s", err)
+	log.Debugf(ctx, "couldn't dereference instance using /.well-known/nodeinfo: %s", err)
 
 	// we couldn't dereference the instance using any of the known methods, so just return a minimal representation
-	log.Debugf("returning minimal representation of instance %s", iri.Host)
+	log.Debugf(ctx, "returning minimal representation of instance %s", iri.Host)
 	id, err := id.NewRandomULID()
 	if err != nil {
 		return nil, fmt.Errorf("error creating new id for instance %s: %s", iri.Host, err)
diff --git a/internal/transport/transport.go b/internal/transport/transport.go
index 8095e6612..18c40f79f 100644
--- a/internal/transport/transport.go
+++ b/internal/transport/transport.go
@@ -130,11 +130,12 @@ func (t *transport) do(r *http.Request, signer func(*http.Request) error) (*http
 	fastFail := IsFastfail(r.Context())
 
 	// Start a log entry for this request
-	l := log.WithFields(kv.Fields{
-		{"pubKeyID", t.pubKeyID},
-		{"method", r.Method},
-		{"url", r.URL.String()},
-	}...)
+	l := log.WithContext(r.Context()).
+		WithFields(kv.Fields{
+			{"pubKeyID", t.pubKeyID},
+			{"method", r.Method},
+			{"url", r.URL.String()},
+		}...)
 
 	r.Header.Set("User-Agent", t.controller.userAgent)