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

1 files changed, 11 insertions, 11 deletions

diff --git a/internal/federation/dereferencing/emoji.go b/internal/federation/dereferencing/emoji.go
index 7d8526c73..15d341383 100644
--- a/internal/federation/dereferencing/emoji.go
+++ b/internal/federation/dereferencing/emoji.go
@@ -111,7 +111,7 @@ func (d *deref) populateEmojis(ctx context.Context, rawEmojis []*gtsmodel.Emoji,
 			// have to get it from the database again
 			gotEmoji = e
 		} else if gotEmoji, err = d.db.GetEmojiByShortcodeDomain(ctx, e.Shortcode, e.Domain); err != nil && err != db.ErrNoEntries {
-			log.Errorf("populateEmojis: error checking database for emoji %s: %s", shortcodeDomain, err)
+			log.Errorf(ctx, "error checking database for emoji %s: %s", shortcodeDomain, err)
 			continue
 		}
 
@@ -120,24 +120,24 @@ func (d *deref) populateEmojis(ctx context.Context, rawEmojis []*gtsmodel.Emoji,
 		if gotEmoji != nil {
 			// we had the emoji already, but refresh it if necessary
 			if e.UpdatedAt.Unix() > gotEmoji.ImageUpdatedAt.Unix() {
-				log.Tracef("populateEmojis: emoji %s was updated since we last saw it, will refresh", shortcodeDomain)
+				log.Tracef(ctx, "emoji %s was updated since we last saw it, will refresh", shortcodeDomain)
 				refresh = true
 			}
 
 			if !refresh && (e.URI != gotEmoji.URI) {
-				log.Tracef("populateEmojis: emoji %s changed URI since we last saw it, will refresh", shortcodeDomain)
+				log.Tracef(ctx, "emoji %s changed URI since we last saw it, will refresh", shortcodeDomain)
 				refresh = true
 			}
 
 			if !refresh && (e.ImageRemoteURL != gotEmoji.ImageRemoteURL) {
-				log.Tracef("populateEmojis: emoji %s changed image URL since we last saw it, will refresh", shortcodeDomain)
+				log.Tracef(ctx, "emoji %s changed image URL since we last saw it, will refresh", shortcodeDomain)
 				refresh = true
 			}
 
 			if !refresh {
-				log.Tracef("populateEmojis: emoji %s is up to date, will not refresh", shortcodeDomain)
+				log.Tracef(ctx, "emoji %s is up to date, will not refresh", shortcodeDomain)
 			} else {
-				log.Tracef("populateEmojis: refreshing emoji %s", shortcodeDomain)
+				log.Tracef(ctx, "refreshing emoji %s", shortcodeDomain)
 				emojiID := gotEmoji.ID // use existing ID
 				processingEmoji, err := d.GetRemoteEmoji(ctx, requestingUsername, e.ImageRemoteURL, e.Shortcode, e.Domain, emojiID, e.URI, &media.AdditionalEmojiInfo{
 					Domain:               &e.Domain,
@@ -147,12 +147,12 @@ func (d *deref) populateEmojis(ctx context.Context, rawEmojis []*gtsmodel.Emoji,
 					VisibleInPicker:      gotEmoji.VisibleInPicker,
 				}, refresh)
 				if err != nil {
-					log.Errorf("populateEmojis: couldn't refresh remote emoji %s: %s", shortcodeDomain, err)
+					log.Errorf(ctx, "couldn't refresh remote emoji %s: %s", shortcodeDomain, err)
 					continue
 				}
 
 				if gotEmoji, err = processingEmoji.LoadEmoji(ctx); err != nil {
-					log.Errorf("populateEmojis: couldn't load refreshed remote emoji %s: %s", shortcodeDomain, err)
+					log.Errorf(ctx, "couldn't load refreshed remote emoji %s: %s", shortcodeDomain, err)
 					continue
 				}
 			}
@@ -160,7 +160,7 @@ func (d *deref) populateEmojis(ctx context.Context, rawEmojis []*gtsmodel.Emoji,
 			// it's new! go get it!
 			newEmojiID, err := id.NewRandomULID()
 			if err != nil {
-				log.Errorf("populateEmojis: error generating id for remote emoji %s: %s", shortcodeDomain, err)
+				log.Errorf(ctx, "error generating id for remote emoji %s: %s", shortcodeDomain, err)
 				continue
 			}
 
@@ -172,12 +172,12 @@ func (d *deref) populateEmojis(ctx context.Context, rawEmojis []*gtsmodel.Emoji,
 				VisibleInPicker:      e.VisibleInPicker,
 			}, refresh)
 			if err != nil {
-				log.Errorf("populateEmojis: couldn't get remote emoji %s: %s", shortcodeDomain, err)
+				log.Errorf(ctx, "couldn't get remote emoji %s: %s", shortcodeDomain, err)
 				continue
 			}
 
 			if gotEmoji, err = processingEmoji.LoadEmoji(ctx); err != nil {
-				log.Errorf("populateEmojis: couldn't load remote emoji %s: %s", shortcodeDomain, err)
+				log.Errorf(ctx, "couldn't load remote emoji %s: %s", shortcodeDomain, err)
 				continue
 			}
 		}