internal/{log,middleware}: add trace ID to context, use in logging

- The requestlog middleware gets the trace ID from the request and
  adds it to the request's context.

- The internal/log package retrieves the traceID and adds it to log
  messages. It also creates two logs instead of one, a "parent" log
  used in requestlog, and a "child" log used for all other logging.
  Together, these two changes will cause the Stackdriver log viewer to
  group all log messages for a request with the request start and end
  log messages.

- These changes require that all log functions take a context, so I
  plumbed one through everywhere. In a handful of cases it didn't seem
  worth doing the plumbing. I used context.TODO() for those so we can
  easily find and re-evalaute them.

Change-Id: I663588463520187d0549a8f802ba9cb44a893592
Reviewed-on: https://team-review.git.corp.google.com/c/golang/discovery/+/622940
Reviewed-by: Robert Findley <rfindley@google.com>

3 files changed, 6 insertions, 6 deletions

diff --git a/internal/postgres/excluded.go b/internal/postgres/excluded.go
index a8186aac..3e45e6ef 100644
--- a/internal/postgres/excluded.go
+++ b/internal/postgres/excluded.go
@@ -22,7 +22,7 @@ func (db *DB) IsExcluded(ctx context.Context, path string) (_ bool, err error) {
 	err = row.Scan(&prefix)
 	switch err {
 	case nil:
-		log.Infof("path %q matched excluded prefix %q", path, prefix)
+		log.Infof(ctx, "path %q matched excluded prefix %q", path, prefix)
 		return true, nil
 	case sql.ErrNoRows:
 		return false, nil
diff --git a/internal/postgres/search.go b/internal/postgres/search.go
index 5a9c032f..964bb0d7 100644
--- a/internal/postgres/search.go
+++ b/internal/postgres/search.go
@@ -901,10 +901,10 @@ func compareImportedByCounts(ctx context.Context, tx *sql.Tx) (err error) {
 	if err := rows.Err(); err != nil {
 		return err
 	}
-	log.Infof("%6d total rows in search_documents match computed_imported_by_counts", total)
-	log.Infof("%6d will change", change)
-	log.Infof("%6d currently have a zero imported-by count", zero)
-	log.Infof("%6d of the non-zero rows will change by more than %d%%", diff, int(changeThreshold*100))
+	log.Infof(ctx, "%6d total rows in search_documents match computed_imported_by_counts", total)
+	log.Infof(ctx, "%6d will change", change)
+	log.Infof(ctx, "%6d currently have a zero imported-by count", zero)
+	log.Infof(ctx, "%6d of the non-zero rows will change by more than %d%%", diff, int(changeThreshold*100))
 	return nil
 }
 
diff --git a/internal/postgres/versionstate.go b/internal/postgres/versionstate.go
index 6832081c..ddb70d5b 100644
--- a/internal/postgres/versionstate.go
+++ b/internal/postgres/versionstate.go
@@ -128,7 +128,7 @@ func (db *DB) UpdateVersionStatesForReprocessing(ctx context.Context, appVersion
 	if err != nil {
 		return fmt.Errorf("result.RowsAffected(): %v", err)
 	}
-	log.Infof("Updated %d module version states to be reprocessed for app_version <= %q", affected, appVersion)
+	log.Infof(ctx, "Updated %d module version states to be reprocessed for app_version <= %q", affected, appVersion)
 	return nil
 }