From cb7802df10b45b61abd8c5238fd0b57b86540325 Mon Sep 17 00:00:00 2001 From: miyuko Date: Sat, 22 Nov 2025 00:27:25 +0000 Subject: [PATCH] Pass the context to logging functions. --- src/auth.go | 31 +++++++++++++++---------------- src/backend_s3.go | 33 ++++++++++++++++----------------- src/caddy.go | 11 +++++------ src/log.go | 42 ++++++++++++++++++++++++++++++++++++++++++ src/main.go | 2 +- src/manifest.go | 11 +++++------ src/migrate.go | 7 +++---- src/pages.go | 5 ++--- src/update.go | 19 +++++++++---------- src/wildcard.go | 3 +-- 10 files changed, 99 insertions(+), 65 deletions(-) create mode 100644 src/log.go diff --git a/src/auth.go b/src/auth.go index c4323d1..0379467 100644 --- a/src/auth.go +++ b/src/auth.go @@ -6,7 +6,6 @@ import ( "encoding/json" "errors" "fmt" - "log" "net" "net/http" "net/url" @@ -32,9 +31,9 @@ func IsUnauthorized(err error) bool { return false } -func authorizeInsecure() *Authorization { +func authorizeInsecure(r *http.Request) *Authorization { if config.Insecure { // for testing only - log.Println("auth: INSECURE mode") + logc.Println(r.Context(), "auth: INSECURE mode") return &Authorization{ repoURLs: nil, branch: "pages", @@ -276,7 +275,7 @@ func authorizeCodebergPagesV2(r *http.Request) (*Authorization, error) { } if len(dnsRecords) > 0 { - log.Printf("auth: %s TXT/CNAME: %q\n", host, dnsRecords) + logc.Printf(r.Context(), "auth: %s TXT/CNAME: %q\n", host, dnsRecords) } for _, dnsRecord := range dnsRecords { @@ -324,7 +323,7 @@ func authorizeCodebergPagesV2(r *http.Request) (*Authorization, error) { func AuthorizeMetadataRetrieval(r *http.Request) (*Authorization, error) { causes := []error{AuthError{http.StatusUnauthorized, "unauthorized"}} - auth := authorizeInsecure() + auth := authorizeInsecure(r) if auth != nil { return auth, nil } @@ -335,7 +334,7 @@ func AuthorizeMetadataRetrieval(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Println("auth: DNS challenge") + logc.Println(r.Context(), "auth: DNS challenge") return auth, nil } @@ -346,7 +345,7 @@ func AuthorizeMetadataRetrieval(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Printf("auth: wildcard %s\n", pattern.GetHost()) + logc.Printf(r.Context(), "auth: wildcard %s\n", pattern.GetHost()) return auth, nil } } @@ -358,7 +357,7 @@ func AuthorizeMetadataRetrieval(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Printf("auth: codeberg %s\n", r.Host) + logc.Printf(r.Context(), "auth: codeberg %s\n", r.Host) return auth, nil } } @@ -376,7 +375,7 @@ func AuthorizeUpdateFromRepository(r *http.Request) (*Authorization, error) { return nil, err } - auth := authorizeInsecure() + auth := authorizeInsecure(r) if auth != nil { return auth, nil } @@ -388,7 +387,7 @@ func AuthorizeUpdateFromRepository(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Println("auth: DNS challenge: allow *") + logc.Println(r.Context(), "auth: DNS challenge: allow *") return auth, nil } @@ -400,7 +399,7 @@ func AuthorizeUpdateFromRepository(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Printf("auth: DNS allowlist: allow %v\n", auth.repoURLs) + logc.Printf(r.Context(), "auth: DNS allowlist: allow %v\n", auth.repoURLs) return auth, nil } } @@ -414,7 +413,7 @@ func AuthorizeUpdateFromRepository(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Printf("auth: wildcard %s: allow %v\n", pattern.GetHost(), auth.repoURLs) + logc.Printf(r.Context(), "auth: wildcard %s: allow %v\n", pattern.GetHost(), auth.repoURLs) return auth, nil } } @@ -426,7 +425,7 @@ func AuthorizeUpdateFromRepository(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Printf("auth: codeberg %s: allow %v branch %s\n", + logc.Printf(r.Context(), "auth: codeberg %s: allow %v branch %s\n", r.Host, auth.repoURLs, auth.branch) return auth, nil } @@ -643,7 +642,7 @@ func AuthorizeUpdateFromArchive(r *http.Request) (*Authorization, error) { return nil, err } - auth := authorizeInsecure() + auth := authorizeInsecure(r) if auth != nil { return auth, nil } @@ -655,7 +654,7 @@ func AuthorizeUpdateFromArchive(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Printf("auth: forge token: allow\n") + logc.Printf(r.Context(), "auth: forge token: allow\n") return auth, nil } @@ -669,7 +668,7 @@ func AuthorizeUpdateFromArchive(r *http.Request) (*Authorization, error) { } else if err != nil { // bad request return nil, err } else { - log.Println("auth: DNS challenge") + logc.Println(r.Context(), "auth: DNS challenge") return auth, nil } } diff --git a/src/backend_s3.go b/src/backend_s3.go index 8dde0e4..badf0dd 100644 --- a/src/backend_s3.go +++ b/src/backend_s3.go @@ -6,7 +6,6 @@ import ( "crypto/sha256" "fmt" "io" - "log" "net/http" "path" "strings" @@ -170,7 +169,7 @@ func NewS3Backend(ctx context.Context, config *S3Config) (*S3Backend, error) { if err != nil { return nil, err } else if !exists { - log.Printf("s3: create bucket %s\n", bucket) + logc.Printf(ctx, "s3: create bucket %s\n", bucket) err = client.MakeBucket(ctx, bucket, minio.MakeBucketOptions{Region: config.Region}) @@ -236,13 +235,13 @@ func (s3 *S3Backend) HasFeature(ctx context.Context, feature BackendFeature) boo minio.StatObjectOptions{}) if err != nil { if errResp := minio.ToErrorResponse(err); errResp.Code == "NoSuchKey" { - log.Printf("s3 feature %q: disabled", feature) + logc.Printf(ctx, "s3 feature %q: disabled", feature) return false, nil } else { return false, err } } - log.Printf("s3 feature %q: enabled", feature) + logc.Printf(ctx, "s3 feature %q: enabled", feature) return true, nil } @@ -250,7 +249,7 @@ func (s3 *S3Backend) HasFeature(ctx context.Context, feature BackendFeature) boo if err != nil { err = fmt.Errorf("getting s3 backend feature %q: %w", feature, err) ObserveError(err) - log.Print(err) + logc.Println(ctx, err) return false } return isOn @@ -268,7 +267,7 @@ func (s3 *S3Backend) GetBlob( reader io.ReadSeeker, size uint64, mtime time.Time, err error, ) { loader := func(ctx context.Context, name string) (*CachedBlob, error) { - log.Printf("s3: get blob %s\n", name) + logc.Printf(ctx, "s3: get blob %s\n", name) startTime := time.Now() @@ -313,7 +312,7 @@ func (s3 *S3Backend) GetBlob( } func (s3 *S3Backend) PutBlob(ctx context.Context, name string, data []byte) error { - log.Printf("s3: put blob %s (%s)\n", name, datasize.ByteSize(len(data)).HumanReadable()) + logc.Printf(ctx, "s3: put blob %s (%s)\n", name, datasize.ByteSize(len(data)).HumanReadable()) _, err := s3.client.StatObject(ctx, s3.bucket, blobObjectName(name), minio.GetObjectOptions{}) @@ -325,7 +324,7 @@ func (s3 *S3Backend) PutBlob(ctx context.Context, name string, data []byte) erro return err } else { ObserveData(ctx, "blob.status", "created") - log.Printf("s3: put blob %s (created)\n", name) + logc.Printf(ctx, "s3: put blob %s (created)\n", name) return nil } } else { @@ -333,7 +332,7 @@ func (s3 *S3Backend) PutBlob(ctx context.Context, name string, data []byte) erro } } else { ObserveData(ctx, "blob.status", "exists") - log.Printf("s3: put blob %s (exists)\n", name) + logc.Printf(ctx, "s3: put blob %s (exists)\n", name) blobsDedupedCount.Inc() blobsDedupedBytes.Add(float64(len(data))) return nil @@ -341,7 +340,7 @@ func (s3 *S3Backend) PutBlob(ctx context.Context, name string, data []byte) erro } func (s3 *S3Backend) DeleteBlob(ctx context.Context, name string) error { - log.Printf("s3: delete blob %s\n", name) + logc.Printf(ctx, "s3: delete blob %s\n", name) return s3.client.RemoveObject(ctx, s3.bucket, blobObjectName(name), minio.RemoveObjectOptions{}) @@ -356,7 +355,7 @@ func stagedManifestObjectName(manifestData []byte) string { } func (s3 *S3Backend) ListManifests(ctx context.Context) (manifests []string, err error) { - log.Print("s3: list manifests") + logc.Print(ctx, "s3: list manifests") ctx, cancel := context.WithCancel(ctx) defer cancel() @@ -396,7 +395,7 @@ func (l s3ManifestLoader) Reload(ctx context.Context, key string, oldValue *Cach } func (l s3ManifestLoader) load(ctx context.Context, name string, oldManifest *CachedManifest) (*CachedManifest, error) { - log.Printf("s3: get manifest %s\n", name) + logc.Printf(ctx, "s3: get manifest %s\n", name) loader := func() (*CachedManifest, error) { opts := minio.GetObjectOptions{} @@ -475,7 +474,7 @@ func (s3 *S3Backend) GetManifest( func (s3 *S3Backend) StageManifest(ctx context.Context, manifest *Manifest) error { data := EncodeManifest(manifest) - log.Printf("s3: stage manifest %x\n", sha256.Sum256(data)) + logc.Printf(ctx, "s3: stage manifest %x\n", sha256.Sum256(data)) _, err := s3.client.PutObject(ctx, s3.bucket, stagedManifestObjectName(data), bytes.NewReader(data), int64(len(data)), minio.PutObjectOptions{}) @@ -484,7 +483,7 @@ func (s3 *S3Backend) StageManifest(ctx context.Context, manifest *Manifest) erro func (s3 *S3Backend) CommitManifest(ctx context.Context, name string, manifest *Manifest) error { data := EncodeManifest(manifest) - log.Printf("s3: commit manifest %x -> %s", sha256.Sum256(data), name) + logc.Printf(ctx, "s3: commit manifest %x -> %s", sha256.Sum256(data), name) // Remove staged object unconditionally (whether commit succeeded or failed), since // the upper layer has to retry the complete operation anyway. @@ -503,7 +502,7 @@ func (s3 *S3Backend) CommitManifest(ctx context.Context, name string, manifest * } func (s3 *S3Backend) DeleteManifest(ctx context.Context, name string) error { - log.Printf("s3: delete manifest %s\n", name) + logc.Printf(ctx, "s3: delete manifest %s\n", name) err := s3.client.RemoveObject(ctx, s3.bucket, manifestObjectName(name), minio.RemoveObjectOptions{}) @@ -516,7 +515,7 @@ func domainCheckObjectName(domain string) string { } func (s3 *S3Backend) CheckDomain(ctx context.Context, domain string) (exists bool, err error) { - log.Printf("s3: check domain %s\n", domain) + logc.Printf(ctx, "s3: check domain %s\n", domain) _, err = s3.client.StatObject(ctx, s3.bucket, domainCheckObjectName(domain), minio.StatObjectOptions{}) @@ -547,7 +546,7 @@ func (s3 *S3Backend) CheckDomain(ctx context.Context, domain string) (exists boo } func (s3 *S3Backend) CreateDomain(ctx context.Context, domain string) error { - log.Printf("s3: create domain %s\n", domain) + logc.Printf(ctx, "s3: create domain %s\n", domain) _, err := s3.client.PutObject(ctx, s3.bucket, domainCheckObjectName(domain), &bytes.Reader{}, 0, minio.PutObjectOptions{}) diff --git a/src/caddy.go b/src/caddy.go index 4252357..3c49f0c 100644 --- a/src/caddy.go +++ b/src/caddy.go @@ -3,7 +3,6 @@ package git_pages import ( "crypto/tls" "fmt" - "log" "net" "net/http" "net/url" @@ -22,7 +21,7 @@ func ServeCaddy(w http.ResponseWriter, r *http.Request) { // this isn't really what git-pages is designed for, and object store accesses can cost money. // [^1]: https://letsencrypt.org/2025/07/01/issuing-our-first-ip-address-certificate if ip := net.ParseIP(domain); ip != nil { - log.Println("caddy:", domain, 404, "(bare IP)") + logc.Println(r.Context(), "caddy:", domain, 404, "(bare IP)") w.WriteHeader(http.StatusNotFound) return } @@ -52,7 +51,7 @@ func ServeCaddy(w http.ResponseWriter, r *http.Request) { } else { connectHost += ":443" } - log.Printf("caddy: check TLS %s", fallbackURL) + logc.Printf(r.Context(), "caddy: check TLS %s", fallbackURL) connection, err := tls.Dial("tcp", connectHost, &tls.Config{ServerName: domain}) if err != nil { continue @@ -64,13 +63,13 @@ func ServeCaddy(w http.ResponseWriter, r *http.Request) { } if found { - log.Println("caddy:", domain, 200) + logc.Println(r.Context(), "caddy:", domain, 200) w.WriteHeader(http.StatusOK) } else if err == nil { - log.Println("caddy:", domain, 404) + logc.Println(r.Context(), "caddy:", domain, 404) w.WriteHeader(http.StatusNotFound) } else { - log.Println("caddy:", domain, 500) + logc.Println(r.Context(), "caddy:", domain, 500) w.WriteHeader(http.StatusInternalServerError) fmt.Fprintln(w, err) } diff --git a/src/log.go b/src/log.go new file mode 100644 index 0000000..88df48b --- /dev/null +++ b/src/log.go @@ -0,0 +1,42 @@ +package git_pages + +import ( + "context" + "fmt" + "log/slog" + "runtime" + "time" +) + +var logc slogWithCtx + +type slogWithCtx struct{} + +func (l slogWithCtx) log(ctx context.Context, level slog.Level, msg string) { + if ctx == nil { + ctx = context.Background() + } + logger := slog.Default() + if !logger.Enabled(ctx, level) { + return + } + + var pcs [1]uintptr + // skip [runtime.Callers, this method, method calling this method] + runtime.Callers(3, pcs[:]) + + r := slog.NewRecord(time.Now(), level, msg, pcs[0]) + logger.Handler().Handle(ctx, r) +} + +func (l slogWithCtx) Print(ctx context.Context, v ...any) { + l.log(ctx, slog.LevelInfo, fmt.Sprint(v...)) +} + +func (l slogWithCtx) Printf(ctx context.Context, format string, v ...any) { + l.log(ctx, slog.LevelInfo, fmt.Sprintf(format, v...)) +} + +func (l slogWithCtx) Println(ctx context.Context, v ...any) { + l.log(ctx, slog.LevelInfo, fmt.Sprintln(v...)) +} diff --git a/src/main.go b/src/main.go index 8368f10..696648f 100644 --- a/src/main.go +++ b/src/main.go @@ -85,7 +85,7 @@ func panicHandler(handler http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { defer func() { if err := recover(); err != nil { - log.Printf("panic: %s %s %s: %s\n%s", + logc.Printf(r.Context(), "panic: %s %s %s: %s\n%s", r.Method, r.Host, r.URL.Path, err, string(debug.Stack())) http.Error(w, fmt.Sprintf("internal server error: %s", err), diff --git a/src/manifest.go b/src/manifest.go index 0e27600..c4daeb4 100644 --- a/src/manifest.go +++ b/src/manifest.go @@ -8,7 +8,6 @@ import ( "crypto/sha256" "errors" "fmt" - "log" "mime" "net/http" "path" @@ -189,7 +188,7 @@ func CompressFiles(ctx context.Context, manifest *Manifest) { if originalSize != 0 { spaceSaving := (float64(originalSize) - float64(compressedSize)) / float64(originalSize) - log.Printf("compress: saved %.2f percent (%s to %s)", + logc.Printf(ctx, "compress: saved %.2f percent (%s to %s)", spaceSaving*100.0, datasize.ByteSize(originalSize).HR(), datasize.ByteSize(compressedSize).HR(), @@ -205,16 +204,16 @@ func CompressFiles(ctx context.Context, manifest *Manifest) { func PrepareManifest(ctx context.Context, manifest *Manifest) error { // Parse Netlify-style `_redirects` if err := ProcessRedirectsFile(manifest); err != nil { - log.Printf("redirects err: %s\n", err) + logc.Printf(ctx, "redirects err: %s\n", err) } else if len(manifest.Redirects) > 0 { - log.Printf("redirects ok: %d rules\n", len(manifest.Redirects)) + logc.Printf(ctx, "redirects ok: %d rules\n", len(manifest.Redirects)) } // Parse Netlify-style `_headers` if err := ProcessHeadersFile(manifest); err != nil { - log.Printf("headers err: %s\n", err) + logc.Printf(ctx, "headers err: %s\n", err) } else if len(manifest.Headers) > 0 { - log.Printf("headers ok: %d rules\n", len(manifest.Headers)) + logc.Printf(ctx, "headers ok: %d rules\n", len(manifest.Headers)) } // Sniff content type like `http.ServeContent` diff --git a/src/migrate.go b/src/migrate.go index 27374e2..812acb6 100644 --- a/src/migrate.go +++ b/src/migrate.go @@ -3,7 +3,6 @@ package git_pages import ( "context" "fmt" - "log" "slices" "strings" ) @@ -19,7 +18,7 @@ func RunMigration(ctx context.Context, name string) error { func createDomainMarkers(ctx context.Context) error { if backend.HasFeature(ctx, FeatureCheckDomainMarker) { - log.Print("store already has domain markers") + logc.Print(ctx, "store already has domain markers") return nil } @@ -36,7 +35,7 @@ func createDomainMarkers(ctx context.Context) error { } } for idx, domain := range domains { - log.Printf("(%d / %d) creating domain %s", idx+1, len(domains), domain) + logc.Printf(ctx, "(%d / %d) creating domain %s", idx+1, len(domains), domain) if err := backend.CreateDomain(ctx, domain); err != nil { return fmt.Errorf("creating domain %s: %w", domain, err) } @@ -44,6 +43,6 @@ func createDomainMarkers(ctx context.Context) error { if err := backend.EnableFeature(ctx, FeatureCheckDomainMarker); err != nil { return err } - log.Printf("created markers for %d domains", len(domains)) + logc.Printf(ctx, "created markers for %d domains", len(domains)) return nil } diff --git a/src/pages.go b/src/pages.go index 2ee310f..e0a263b 100644 --- a/src/pages.go +++ b/src/pages.go @@ -8,7 +8,6 @@ import ( "errors" "fmt" "io" - "log" "maps" "net/http" "net/url" @@ -652,7 +651,7 @@ func ServePages(w http.ResponseWriter, r *http.Request) { // any intentional deviation is an opportunity to miss an issue that will affect our // visitors but not our health checks. if r.Header.Get("Health-Check") == "" { - log.Println("pages:", r.Method, r.Host, r.URL, r.Header.Get("Content-Type")) + logc.Println(r.Context(), "pages:", r.Method, r.Host, r.URL, r.Header.Get("Content-Type")) if region := os.Getenv("FLY_REGION"); region != "" { machine_id := os.Getenv("FLY_MACHINE_ID") w.Header().Add("Server", fmt.Sprintf("git-pages (fly.io; %s; %s)", region, machine_id)) @@ -695,6 +694,6 @@ func ServePages(w http.ResponseWriter, r *http.Request) { http.Error(w, message, http.StatusRequestEntityTooLarge) err = errors.New(message) } - log.Println("pages err:", err) + logc.Println(r.Context(), "pages err:", err) } } diff --git a/src/update.go b/src/update.go index 9a61024..bb26883 100644 --- a/src/update.go +++ b/src/update.go @@ -5,7 +5,6 @@ import ( "errors" "fmt" "io" - "log" "strings" ) @@ -71,12 +70,12 @@ func Update(ctx context.Context, webRoot string, manifest *Manifest) UpdateResul status = "unchanged" } if newManifest.Commit != nil { - log.Printf("update %s ok: %s %s", webRoot, status, *newManifest.Commit) + logc.Printf(ctx, "update %s ok: %s %s", webRoot, status, *newManifest.Commit) } else { - log.Printf("update %s ok: %s", webRoot, status) + logc.Printf(ctx, "update %s ok: %s", webRoot, status) } } else { - log.Printf("update %s err: %s", webRoot, err) + logc.Printf(ctx, "update %s err: %s", webRoot, err) } return UpdateResult{outcome, newManifest, err} @@ -91,7 +90,7 @@ func UpdateFromRepository( span, ctx := ObserveFunction(ctx, "UpdateFromRepository", "repo.url", repoURL) defer span.Finish() - log.Printf("update %s: %s %s\n", webRoot, repoURL, branch) + logc.Printf(ctx, "update %s: %s %s\n", webRoot, repoURL, branch) manifest, err := FetchRepository(ctx, repoURL, branch) if errors.Is(err, context.DeadlineExceeded) { @@ -119,23 +118,23 @@ func UpdateFromArchive( switch contentType { case "application/x-tar": - log.Printf("update %s: (tar)", webRoot) + logc.Printf(ctx, "update %s: (tar)", webRoot) manifest, err = ExtractTar(reader) // yellow? case "application/x-tar+gzip": - log.Printf("update %s: (tar.gz)", webRoot) + logc.Printf(ctx, "update %s: (tar.gz)", webRoot) manifest, err = ExtractTarGzip(reader) // definitely yellow. case "application/x-tar+zstd": - log.Printf("update %s: (tar.zst)", webRoot) + logc.Printf(ctx, "update %s: (tar.zst)", webRoot) manifest, err = ExtractTarZstd(reader) case "application/zip": - log.Printf("update %s: (zip)", webRoot) + logc.Printf(ctx, "update %s: (zip)", webRoot) manifest, err = ExtractZip(reader) default: err = errArchiveFormat } if err != nil { - log.Printf("update %s err: %s", webRoot, err) + logc.Printf(ctx, "update %s err: %s", webRoot, err) result = UpdateResult{UpdateError, nil, err} } else { result = Update(ctx, webRoot, manifest) diff --git a/src/wildcard.go b/src/wildcard.go index 7a2f0d9..f23ca0b 100644 --- a/src/wildcard.go +++ b/src/wildcard.go @@ -3,7 +3,6 @@ package git_pages import ( "crypto/tls" "fmt" - "log" "net/http" "net/http/httputil" "net/url" @@ -95,7 +94,7 @@ func HandleWildcardFallback(w http.ResponseWriter, r *http.Request) (bool, error for _, pattern := range wildcards { if pattern.IsFallbackFor(host) { - log.Printf("proxy: %s via %s", pattern.GetHost(), pattern.FallbackURL) + logc.Printf(r.Context(), "proxy: %s via %s", pattern.GetHost(), pattern.FallbackURL) pattern.Fallback.ServeHTTP(w, r) return true, nil }