[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>

5 files changed, 53 insertions, 92 deletions

diff --git a/internal/timeline/get.go b/internal/timeline/get.go
index 4bad67a6b..f9a5444fc 100644
--- a/internal/timeline/get.go
+++ b/internal/timeline/get.go
@@ -38,14 +38,15 @@ func (t *timeline) LastGot() time.Time {
 }
 
 func (t *timeline) Get(ctx context.Context, amount int, maxID string, sinceID string, minID string, prepareNext bool) ([]Preparable, error) {
-	l := log.WithFields(kv.Fields{
-		{"accountID", t.accountID},
-		{"amount", amount},
-		{"maxID", maxID},
-		{"sinceID", sinceID},
-		{"minID", minID},
-	}...)
-	l.Debug("entering get and updating t.lastGot")
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"accountID", t.accountID},
+			{"amount", amount},
+			{"maxID", maxID},
+			{"sinceID", sinceID},
+			{"minID", minID},
+		}...)
+	l.Trace("entering get and updating t.lastGot")
 
 	// regardless of what happens below, update the
 	// last time Get was called for this timeline
@@ -154,11 +155,12 @@ func (t *timeline) getXFromTop(ctx context.Context, amount int) ([]Preparable, e
 //
 // This corresponds to an api call to /timelines/home?max_id=WHATEVER
 func (t *timeline) getXBehindID(ctx context.Context, amount int, behindID string, attempts *int) ([]Preparable, error) {
-	l := log.WithFields(kv.Fields{
-		{"amount", amount},
-		{"behindID", behindID},
-		{"attempts", attempts},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"amount", amount},
+			{"behindID", behindID},
+			{"attempts", attempts},
+		}...)
 
 	newAttempts := *attempts
 	newAttempts++
diff --git a/internal/timeline/index.go b/internal/timeline/index.go
index a85863f21..e7e0e17fe 100644
--- a/internal/timeline/index.go
+++ b/internal/timeline/index.go
@@ -35,58 +35,9 @@ func (t *timeline) ItemIndexLength(ctx context.Context) int {
 	return t.indexedItems.data.Len()
 }
 
-// func (t *timeline) indexBefore(ctx context.Context, itemID string, amount int) error {
-// 	l := log.WithFields(kv.Fields{{"amount", amount}}...)
-
-// 	// lazily initialize index if it hasn't been done already
-// 	if t.indexedItems.data == nil {
-// 		t.indexedItems.data = &list.List{}
-// 		t.indexedItems.data.Init()
-// 	}
-
-// 	toIndex := []Timelineable{}
-// 	offsetID := itemID
-
-// 	l.Trace("entering grabloop")
-// grabloop:
-// 	for i := 0; len(toIndex) < amount && i < 5; i++ { // try the grabloop 5 times only
-// 		// first grab items using the caller-provided grab function
-// 		l.Trace("grabbing...")
-// 		items, stop, err := t.grabFunction(ctx, t.accountID, "", "", offsetID, amount)
-// 		if err != nil {
-// 			return err
-// 		}
-// 		if stop {
-// 			break grabloop
-// 		}
-
-// 		l.Trace("filtering...")
-// 		// now filter each item using the caller-provided filter function
-// 		for _, item := range items {
-// 			shouldIndex, err := t.filterFunction(ctx, t.accountID, item)
-// 			if err != nil {
-// 				return err
-// 			}
-// 			if shouldIndex {
-// 				toIndex = append(toIndex, item)
-// 			}
-// 			offsetID = item.GetID()
-// 		}
-// 	}
-// 	l.Trace("left grabloop")
-
-// 	// index the items we got
-// 	for _, s := range toIndex {
-// 		if _, err := t.IndexOne(ctx, s.GetID(), s.GetBoostOfID(), s.GetAccountID(), s.GetBoostOfAccountID()); err != nil {
-// 			return fmt.Errorf("indexBefore: error indexing item with id %s: %s", s.GetID(), err)
-// 		}
-// 	}
-
-// 	return nil
-// }
-
 func (t *timeline) indexBehind(ctx context.Context, itemID string, amount int) error {
-	l := log.WithFields(kv.Fields{{"amount", amount}}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{{"amount", amount}}...)
 
 	// lazily initialize index if it hasn't been done already
 	if t.indexedItems.data == nil {
diff --git a/internal/timeline/manager.go b/internal/timeline/manager.go
index 83d138f51..48c4bec83 100644
--- a/internal/timeline/manager.go
+++ b/internal/timeline/manager.go
@@ -134,10 +134,11 @@ func (m *manager) Stop() error {
 }
 
 func (m *manager) Ingest(ctx context.Context, item Timelineable, timelineAccountID string) (bool, error) {
-	l := log.WithFields(kv.Fields{
-		{"timelineAccountID", timelineAccountID},
-		{"itemID", item.GetID()},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"timelineAccountID", timelineAccountID},
+			{"itemID", item.GetID()},
+		}...)
 
 	t, err := m.getOrCreateTimeline(ctx, timelineAccountID)
 	if err != nil {
@@ -149,10 +150,11 @@ func (m *manager) Ingest(ctx context.Context, item Timelineable, timelineAccount
 }
 
 func (m *manager) IngestAndPrepare(ctx context.Context, item Timelineable, timelineAccountID string) (bool, error) {
-	l := log.WithFields(kv.Fields{
-		{"timelineAccountID", timelineAccountID},
-		{"itemID", item.GetID()},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"timelineAccountID", timelineAccountID},
+			{"itemID", item.GetID()},
+		}...)
 
 	t, err := m.getOrCreateTimeline(ctx, timelineAccountID)
 	if err != nil {
@@ -164,10 +166,11 @@ func (m *manager) IngestAndPrepare(ctx context.Context, item Timelineable, timel
 }
 
 func (m *manager) Remove(ctx context.Context, timelineAccountID string, itemID string) (int, error) {
-	l := log.WithFields(kv.Fields{
-		{"timelineAccountID", timelineAccountID},
-		{"itemID", itemID},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"timelineAccountID", timelineAccountID},
+			{"itemID", itemID},
+		}...)
 
 	t, err := m.getOrCreateTimeline(ctx, timelineAccountID)
 	if err != nil {
@@ -179,7 +182,8 @@ func (m *manager) Remove(ctx context.Context, timelineAccountID string, itemID s
 }
 
 func (m *manager) GetTimeline(ctx context.Context, timelineAccountID string, maxID string, sinceID string, minID string, limit int, local bool) ([]Preparable, error) {
-	l := log.WithFields(kv.Fields{{"timelineAccountID", timelineAccountID}}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{{"timelineAccountID", timelineAccountID}}...)
 
 	t, err := m.getOrCreateTimeline(ctx, timelineAccountID)
 	if err != nil {
diff --git a/internal/timeline/prepare.go b/internal/timeline/prepare.go
index 41ef36fed..fbf2d9d9e 100644
--- a/internal/timeline/prepare.go
+++ b/internal/timeline/prepare.go
@@ -31,7 +31,8 @@ import (
 )
 
 func (t *timeline) PrepareFromTop(ctx context.Context, amount int) error {
-	l := log.WithFields(kv.Fields{{"amount", amount}}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{{"amount", amount}}...)
 
 	// lazily initialize prepared posts if it hasn't been done already
 	if t.preparedItems.data == nil {
@@ -85,12 +86,13 @@ prepareloop:
 }
 
 func (t *timeline) prepareNextQuery(ctx context.Context, amount int, maxID string, sinceID string, minID string) error {
-	l := log.WithFields(kv.Fields{
-		{"amount", amount},
-		{"maxID", maxID},
-		{"sinceID", sinceID},
-		{"minID", minID},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"amount", amount},
+			{"maxID", maxID},
+			{"sinceID", sinceID},
+			{"minID", minID},
+		}...)
 
 	var err error
 	switch {
diff --git a/internal/timeline/remove.go b/internal/timeline/remove.go
index f0bd4618b..1693ed03a 100644
--- a/internal/timeline/remove.go
+++ b/internal/timeline/remove.go
@@ -28,10 +28,11 @@ import (
 )
 
 func (t *timeline) Remove(ctx context.Context, statusID string) (int, error) {
-	l := log.WithFields(kv.Fields{
-		{"accountTimeline", t.accountID},
-		{"statusID", statusID},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"accountTimeline", t.accountID},
+			{"statusID", statusID},
+		}...)
 
 	t.Lock()
 	defer t.Unlock()
@@ -80,10 +81,11 @@ func (t *timeline) Remove(ctx context.Context, statusID string) (int, error) {
 }
 
 func (t *timeline) RemoveAllBy(ctx context.Context, accountID string) (int, error) {
-	l := log.WithFields(kv.Fields{
-		{"accountTimeline", t.accountID},
-		{"accountID", accountID},
-	}...)
+	l := log.WithContext(ctx).
+		WithFields(kv.Fields{
+			{"accountTimeline", t.accountID},
+			{"accountID", accountID},
+		}...)
 
 	t.Lock()
 	defer t.Unlock()