git-pages/src/observe.go

package git_pages

import (
	"context"
	"errors"
	"fmt"
	"io"
	"iter"
	"log"
	"log/slog"
	"net/http"
	"os"
	"runtime/debug"
	"sync"
	"time"

	slogmulti "github.com/samber/slog-multi"

	syslog "codeberg.org/git-pages/go-slog-syslog"

	"github.com/prometheus/client_golang/prometheus"
	"github.com/prometheus/client_golang/prometheus/promauto"
)

var (
	httpRequestCount = promauto.NewCounterVec(prometheus.CounterOpts{
		Name: "git_pages_http_request_count",
		Help: "Count of HTTP requests by method and response status code",
	}, []string{"method", "code"})

	httpRequestDurationSeconds = promauto.NewHistogramVec(prometheus.HistogramOpts{
		Name:    "git_pages_http_request_duration_seconds",
		Help:    "Time to respond to incoming HTTP requests",
		Buckets: []float64{.005, .01, .025, .05, .1, .25, .5, 1, 2.5, 5, 10},

		NativeHistogramBucketFactor:     1.1,
		NativeHistogramMaxBucketNumber:  100,
		NativeHistogramMinResetDuration: 10 * time.Minute,
	}, []string{"method"})
)

var syslogHandler syslog.Handler

func InitObservability() {
	debug.SetPanicOnFault(true)

	logHandlers := []slog.Handler{}

	switch config.LogFormat {
	case "none":
		// nothing to do
	case "text":
		logHandlers = append(logHandlers,
			slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{}))
	case "json":
		logHandlers = append(logHandlers,
			slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{}))
	default:
		log.Println("unknown log format", config.LogFormat)
	}

	if syslogAddr := os.Getenv("SYSLOG_ADDR"); syslogAddr != "" {
		var err error
		syslogHandler, err = syslog.NewHandler(&syslog.HandlerOptions{
			Address:          syslogAddr,
			AppName:          "git-pages",
			StructuredDataID: "git-pages",
		})
		if err != nil {
			log.Fatalf("syslog: %v", err)
		}
		logHandlers = append(logHandlers, syslogHandler)
	}

	slog.SetDefault(slog.New(slogmulti.Fanout(logHandlers...)))
}

func FiniObservability() {
	var wg sync.WaitGroup
	timeout := 2 * time.Second
	if syslogHandler != nil {
		wg.Go(func() { syslogHandler.Flush(timeout) })
	}
	wg.Wait()
}

func ObserveError(err error) {
	if errors.Is(err, context.Canceled) {
		// Something has explicitly requested cancellation.
		// Timeout results in a different error.
		return
	}
}

type observedResponseWriter struct {
	inner  http.ResponseWriter
	status int
}

func newObservedResponseWriter(w http.ResponseWriter) observedResponseWriter {
	return observedResponseWriter{
		inner:  w,
		status: 0,
	}
}

func (w *observedResponseWriter) Unwrap() http.ResponseWriter {
	return w.inner
}

func (w *observedResponseWriter) Header() http.Header {
	return w.inner.Header()
}

func (w *observedResponseWriter) Write(data []byte) (int, error) {
	return w.inner.Write(data)
}

func (w *observedResponseWriter) WriteHeader(statusCode int) {
	w.status = statusCode
	w.inner.WriteHeader(statusCode)
}

func ObserveHTTPHandler(handler http.Handler) http.Handler {
	handler = func(next http.Handler) http.Handler {
		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
			ow := newObservedResponseWriter(w)

			start := time.Now()
			next.ServeHTTP(&ow, r)
			duration := time.Since(start)

			httpRequestCount.
				With(prometheus.Labels{"method": r.Method, "code": fmt.Sprintf("%d", ow.status)}).
				Inc()
			httpRequestDurationSeconds.
				With(prometheus.Labels{"method": r.Method}).
				Observe(duration.Seconds())
		})
	}(handler)

	return handler
}

type noopSpan struct{}

func (span noopSpan) Finish() {}

func ObserveFunction(
	ctx context.Context, funcName string, data ...any,
) (
	interface{ Finish() }, context.Context,
) {
	switch {
	default:
		return noopSpan{}, ctx
	}
}

func ObserveData(ctx context.Context, data ...any) {
}

var (
	blobsRetrievedCount = promauto.NewCounter(prometheus.CounterOpts{
		Name: "git_pages_blobs_retrieved",
		Help: "Count of blobs retrieved",
	})
	blobsRetrievedBytes = promauto.NewCounter(prometheus.CounterOpts{
		Name: "git_pages_blobs_retrieved_bytes",
		Help: "Total size in bytes of blobs retrieved",
	})

	blobsStoredCount = promauto.NewCounter(prometheus.CounterOpts{
		Name: "git_pages_blobs_stored",
		Help: "Count of blobs stored",
	})
	blobsStoredBytes = promauto.NewCounter(prometheus.CounterOpts{
		Name: "git_pages_blobs_stored_bytes",
		Help: "Total size in bytes of blobs stored",
	})

	manifestsRetrievedCount = promauto.NewCounter(prometheus.CounterOpts{
		Name: "git_pages_manifests_retrieved",
		Help: "Count of manifests retrieved",
	})
)

type observedBackend struct {
	inner Backend
}

var _ Backend = (*observedBackend)(nil)

func NewObservedBackend(backend Backend) Backend {
	return &observedBackend{inner: backend}
}

func (backend *observedBackend) HasFeature(ctx context.Context, feature BackendFeature) (isOn bool) {
	span, ctx := ObserveFunction(ctx, "HasFeature")
	isOn = backend.inner.HasFeature(ctx, feature)
	span.Finish()
	return
}

func (backend *observedBackend) EnableFeature(ctx context.Context, feature BackendFeature) (err error) {
	span, ctx := ObserveFunction(ctx, "EnableFeature")
	err = backend.inner.EnableFeature(ctx, feature)
	span.Finish()
	return
}

func (backend *observedBackend) GetBlob(
	ctx context.Context, name string,
) (
	reader io.ReadSeeker, metadata BlobMetadata, err error,
) {
	span, ctx := ObserveFunction(ctx, "GetBlob", "blob.name", name)
	if reader, metadata, err = backend.inner.GetBlob(ctx, name); err == nil {
		ObserveData(ctx, "blob.size", metadata.Size)
		blobsRetrievedCount.Inc()
		blobsRetrievedBytes.Add(float64(metadata.Size))
	}
	span.Finish()
	return
}

func (backend *observedBackend) PutBlob(ctx context.Context, name string, data []byte) (err error) {
	span, ctx := ObserveFunction(ctx, "PutBlob", "blob.name", name, "blob.size", len(data))
	if err = backend.inner.PutBlob(ctx, name, data); err == nil {
		blobsStoredCount.Inc()
		blobsStoredBytes.Add(float64(len(data)))
	}
	span.Finish()
	return
}

func (backend *observedBackend) DeleteBlob(ctx context.Context, name string) (err error) {
	span, ctx := ObserveFunction(ctx, "DeleteBlob", "blob.name", name)
	err = backend.inner.DeleteBlob(ctx, name)
	span.Finish()
	return
}

func (backend *observedBackend) EnumerateBlobs(ctx context.Context) iter.Seq2[BlobMetadata, error] {
	return func(yield func(BlobMetadata, error) bool) {
		span, ctx := ObserveFunction(ctx, "EnumerateBlobs")
		for metadata, err := range backend.inner.EnumerateBlobs(ctx) {
			if !yield(metadata, err) {
				break
			}
		}
		span.Finish()
	}
}

func (backend *observedBackend) GetManifest(
	ctx context.Context, name string, opts GetManifestOptions,
) (
	manifest *Manifest, metadata ManifestMetadata, err error,
) {
	span, ctx := ObserveFunction(ctx, "GetManifest",
		"manifest.name", name,
		"manifest.bypass_cache", opts.BypassCache,
	)
	if manifest, metadata, err = backend.inner.GetManifest(ctx, name, opts); err == nil {
		manifestsRetrievedCount.Inc()
	}
	span.Finish()
	return
}

func (backend *observedBackend) StageManifest(ctx context.Context, manifest *Manifest) (err error) {
	span, ctx := ObserveFunction(ctx, "StageManifest")
	err = backend.inner.StageManifest(ctx, manifest)
	span.Finish()
	return
}

func (backend *observedBackend) HasAtomicCAS(ctx context.Context) bool {
	return backend.inner.HasAtomicCAS(ctx)
}

func (backend *observedBackend) CommitManifest(ctx context.Context, name string, manifest *Manifest, opts ModifyManifestOptions) (err error) {
	span, ctx := ObserveFunction(ctx, "CommitManifest", "manifest.name", name)
	err = backend.inner.CommitManifest(ctx, name, manifest, opts)
	span.Finish()
	return
}

func (backend *observedBackend) DeleteManifest(ctx context.Context, name string, opts ModifyManifestOptions) (err error) {
	span, ctx := ObserveFunction(ctx, "DeleteManifest", "manifest.name", name)
	err = backend.inner.DeleteManifest(ctx, name, opts)
	span.Finish()
	return
}

func (backend *observedBackend) ExpireManifest(ctx context.Context, name string) (err error) {
	span, ctx := ObserveFunction(ctx, "ExpireManifest", "manifest.name", name)
	err = backend.inner.ExpireManifest(ctx, name)
	span.Finish()
	return
}

func (backend *observedBackend) EnumerateManifests(ctx context.Context) iter.Seq2[*ManifestMetadata, error] {
	return func(yield func(*ManifestMetadata, error) bool) {
		span, ctx := ObserveFunction(ctx, "EnumerateManifests")
		for metadata, err := range backend.inner.EnumerateManifests(ctx) {
			if !yield(metadata, err) {
				break
			}
		}
		span.Finish()
	}
}

func (backend *observedBackend) GetAllManifests(ctx context.Context) iter.Seq2[tuple[*ManifestMetadata, *Manifest], error] {
	return func(yield func(tuple[*ManifestMetadata, *Manifest], error) bool) {
		span, ctx := ObserveFunction(ctx, "GetAllManifests")
		for item, err := range backend.inner.GetAllManifests(ctx) {
			if !yield(item, err) {
				break
			}
		}
		span.Finish()
	}
}

func (backend *observedBackend) CheckDomain(ctx context.Context, domain string) (found bool, err error) {
	span, ctx := ObserveFunction(ctx, "CheckDomain", "domain.name", domain)
	found, err = backend.inner.CheckDomain(ctx, domain)
	span.Finish()
	return
}

func (backend *observedBackend) CreateDomain(ctx context.Context, domain string) (err error) {
	span, ctx := ObserveFunction(ctx, "CreateDomain", "domain.name", domain)
	err = backend.inner.CreateDomain(ctx, domain)
	span.Finish()
	return
}

func (backend *observedBackend) FreezeDomain(ctx context.Context, domain string) (err error) {
	span, ctx := ObserveFunction(ctx, "FreezeDomain", "domain.name", domain)
	err = backend.inner.FreezeDomain(ctx, domain)
	span.Finish()
	return
}

func (backend *observedBackend) UnfreezeDomain(ctx context.Context, domain string) (err error) {
	span, ctx := ObserveFunction(ctx, "UnfreezeDomain", "domain.name", domain)
	err = backend.inner.UnfreezeDomain(ctx, domain)
	span.Finish()
	return
}

func (backend *observedBackend) HasSiteListChanged(ctx context.Context, since time.Time) (changed bool, err error) {
	span, ctx := ObserveFunction(ctx, "HasSiteListChanged", "since", since)
	changed, err = backend.inner.HasSiteListChanged(ctx, since)
	span.Finish()
	return
}

func (backend *observedBackend) AppendAuditLog(ctx context.Context, id AuditID, record *AuditRecord) (err error) {
	span, ctx := ObserveFunction(ctx, "AppendAuditLog", "audit.id", id)
	err = backend.inner.AppendAuditLog(ctx, id, record)
	span.Finish()
	return
}

func (backend *observedBackend) QueryAuditLog(ctx context.Context, id AuditID) (record *AuditRecord, err error) {
	span, ctx := ObserveFunction(ctx, "QueryAuditLog", "audit.id", id)
	record, err = backend.inner.QueryAuditLog(ctx, id)
	span.Finish()
	return
}

func (backend *observedBackend) SearchAuditLog(
	ctx context.Context, opts SearchAuditLogOptions,
) iter.Seq2[AuditID, error] {
	return func(yield func(AuditID, error) bool) {
		span, ctx := ObserveFunction(ctx, "SearchAuditLog",
			"audit.search.since", opts.Since,
			"audit.search.until", opts.Until,
		)
		for id, err := range backend.inner.SearchAuditLog(ctx, opts) {
			if !yield(id, err) {
				break
			}
		}
		span.Finish()
	}
}

func (backend *observedBackend) GetAuditLogRecords(
	ctx context.Context, ids iter.Seq2[AuditID, error],
) iter.Seq2[*AuditRecord, error] {
	return func(yield func(*AuditRecord, error) bool) {
		span, ctx := ObserveFunction(ctx, "GetAuditLogRecords")
		for item, err := range backend.inner.GetAuditLogRecords(ctx, ids) {
			if !yield(item, err) {
				break
			}
		}
		span.Finish()
	}
}

func (backend *observedBackend) DetachAuditRecord(ctx context.Context, id AuditID) (err error) {
	span, ctx := ObserveFunction(ctx, "DetachAuditRecord", "audit.id", id)
	err = backend.inner.DetachAuditRecord(ctx, id)
	span.Finish()
	return
}

func (backend *observedBackend) ExpireAuditRecord(ctx context.Context, id AuditID) (err error) {
	span, ctx := ObserveFunction(ctx, "ExpireAuditRecord", "audit.id", id)
	err = backend.inner.ExpireAuditRecord(ctx, id)
	span.Finish()
	return
}