pixa/internal/handlers/request_id_internal_test.go

package handlers

import (
	"bytes"
	"context"
	"encoding/json"
	"io"
	"log/slog"
	"net/http"
	"net/http/httptest"
	"testing"
	"time"

	"github.com/go-chi/chi/v5/middleware"

	"sneak.berlin/go/pixa/internal/imagerequest"
)

// signedPhotoURL returns a signed /v1/image/ URL, valid for a minute, for the
// JPEG at photoPath on signedHost at 50x50. It is signed with testSigningKey,
// the key of the image service newSignedHostServer builds. It takes a Handlers
// it does not use, so that it has the type of encPhotoURL.
func signedPhotoURL(t *testing.T, _ *Handlers) string {
	t.Helper()

	return generateSignedURL(testSigningKey, &imagerequest.Request{
		Source: imagerequest.Source{
			Host: signedHost,
			Path: photoPath,
		},
		Transform: imagerequest.Transform{
			Size:   imagerequest.Size{Width: 50, Height: 50},
			Format: imagerequest.FormatJPEG,
		},
	}, time.Minute)
}

// encPhotoURL returns an encrypted /v1/e/ URL, which never expires, for the
// JPEG at photoPath on signedHost at 50x50, made with h's generator.
func encPhotoURL(t *testing.T, h *Handlers) string {
	t.Helper()

	token, err := h.encGen.Generate(&imagerequest.Request{
		Source: imagerequest.Source{
			Host: signedHost,
			Path: photoPath,
		},
		Transform: imagerequest.Transform{
			Size:   imagerequest.Size{Width: 50, Height: 50},
			Format: imagerequest.FormatJPEG,
		},
	})
	if err != nil {
		t.Fatalf("Generate() error = %v", err)
	}

	return "/v1/e/" + token + "/img.jpg"
}

// requestIDByMessage reads the JSON log lines in logs and returns the
// request_id of each line, by its message.
func requestIDByMessage(t *testing.T, logs io.Reader) map[string]string {
	t.Helper()

	logged := make(map[string]string)

	dec := json.NewDecoder(logs)
	for dec.More() {
		var line map[string]any

		err := dec.Decode(&line)
		if err != nil {
			t.Fatalf("decoding log line: %v", err)
		}

		msg, _ := line["msg"].(string)
		requestID, _ := line["request_id"].(string)
		logged[msg] = requestID
	}

	return logged
}

// TestImageLogLinesCarryRequestID verifies that the lines logged when an image
// is fetched, converted and served through either image route carry the
// request's ID as request_id, as the request log line does, so they can be
// found from it.
func TestImageLogLinesCarryRequestID(t *testing.T) {
	t.Parallel()

	const requestID = "test-request-id"

	imageURLs := map[string]func(*testing.T, *Handlers) string{
		"/v1/image/": signedPhotoURL,
		"/v1/e/":     encPhotoURL,
	}

	for route, imageURL := range imageURLs {
		t.Run(route, func(t *testing.T) {
			t.Parallel()

			var logs bytes.Buffer

			h, srv := newSignedHostServer(t,
				slog.New(slog.NewJSONHandler(&logs, nil)))

			ctx := context.WithValue(t.Context(),
				middleware.RequestIDKey, requestID)
			rec := httptest.NewRecorder()
			srv.ServeHTTP(rec, httptest.NewRequestWithContext(
				ctx, http.MethodGet, imageURL(t, h), nil))

			if rec.Code != http.StatusOK {
				t.Fatalf("status = %d, want %d", rec.Code, http.StatusOK)
			}

			t.Logf("logged:\n%s", logs.String())

			logged := requestIDByMessage(t, &logs)

			for _, msg := range []string{
				"upstream fetched", "image converted", "image served",
			} {
				got, ok := logged[msg]
				if !ok {
					t.Errorf("no %q line logged", msg)
				} else if got != requestID {
					t.Errorf("%q line has request_id %q, want %q",
						msg, got, requestID)
				}
			}
		})
	}
}