Pass the context to logging functions.

This commit is contained in:
miyuko
2025-11-22 00:27:25 +00:00
parent b01e67f993
commit cb7802df10
10 changed files with 99 additions and 65 deletions

View File

@@ -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
}
}

View File

@@ -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{})

View File

@@ -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)
}

42
src/log.go Normal file
View File

@@ -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...))
}

View File

@@ -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),

View File

@@ -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`

View File

@@ -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
}

View File

@@ -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)
}
}

View File

@@ -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)

View File

@@ -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
}