// Package imageproxy fetches, transforms, caches and serves images. Its // Proxy serves an image from the cache when it can, and otherwise makes it // from the cached or fetched source image. package imageproxy import ( "bytes" "context" "errors" "fmt" "io" "log/slog" "runtime/debug" "time" "github.com/dustin/go-humanize" "github.com/getsentry/sentry-go" "github.com/go-chi/chi/v5/middleware" "github.com/prometheus/client_golang/prometheus" "golang.org/x/sync/singleflight" "sneak.berlin/go/pixa/internal/httpfetcher" "sneak.berlin/go/pixa/internal/imageprocessor" "sneak.berlin/go/pixa/internal/imagerequest" "sneak.berlin/go/pixa/internal/imgcache" "sneak.berlin/go/pixa/internal/magic" ) // Proxy orchestrates the cache, fetcher, and processor. type Proxy struct { cache *imgcache.Cache fetcher httpfetcher.Fetcher processor *imageprocessor.ImageProcessor log *slog.Logger maxResponseSize int64 // variantsInProgress lets the requests that miss the same variant at the // same time share one fetch and one transcode. variantsInProgress singleflight.Group // The counts of upstream fetches and transforms, made and registered by // New. They are kept in memory, so adding to one waits for nothing. upstreamFetches prometheus.Counter upstreamFetchBytes prometheus.Counter transforms prometheus.Counter } // Config holds the proxy's configuration. type Config struct { // Cache is the cache instance Cache *imgcache.Cache // Fetcher fetches source images from upstream hosts Fetcher httpfetcher.Fetcher // Processor converts and resizes the images Processor *imageprocessor.ImageProcessor // MaxResponseSize is the largest source accepted, in bytes; a cached // source larger than this is fetched again MaxResponseSize int64 // Logger for logging Logger *slog.Logger } // errCacheRequired is returned when the proxy is built without a cache. var errCacheRequired = errors.New("cache is required") // New creates a new image proxy and registers its counters on // metricsRegistry. pixad passes Prometheus' default registry, the one // /metrics serves. It fails when metricsRegistry already holds counters of // the same names. func New( cfg *Config, metricsRegistry prometheus.Registerer, ) (*Proxy, error) { if cfg.Cache == nil { return nil, errCacheRequired } log := cfg.Logger if log == nil { log = slog.Default() } // JPEG XL is the default output format, so pixad does not start // without it. err := imageprocessor.CheckJPEGXLSupport() if err != nil { return nil, err } p := &Proxy{ cache: cfg.Cache, fetcher: cfg.Fetcher, processor: cfg.Processor, log: log, maxResponseSize: cfg.MaxResponseSize, upstreamFetches: prometheus.NewCounter(prometheus.CounterOpts{ Name: "pixa_upstream_fetches_total", Help: "Fetches of a source image from upstream that read any bytes.", }), upstreamFetchBytes: prometheus.NewCounter(prometheus.CounterOpts{ Name: "pixa_upstream_fetch_bytes_total", Help: "Bytes read from upstream by fetches of source images.", }), transforms: prometheus.NewCounter(prometheus.CounterOpts{ Name: "pixa_transforms_total", Help: "Images the image processor transformed.", }), } for _, counter := range []prometheus.Counter{ p.upstreamFetches, p.upstreamFetchBytes, p.transforms, } { err = metricsRegistry.Register(counter) if err != nil { return nil, fmt.Errorf("failed to register the proxy's counters: %w", err) } } return p, nil } // ErrNegativeCached is returned when a URL is in the negative cache (recently failed). var ErrNegativeCached = errors.New("request is in negative cache (recently failed)") // ErrProcessingTimedOut is returned when processing an image stopped because // the downstream_timeout of the request doing it ended, to that request and to // every request that waited for its image. var ErrProcessingTimedOut = errors.New( "image processing stopped at the deadline of the request doing it") // ImageResponse represents a processed image ready to serve type ImageResponse struct { // Content is the image data reader Content io.ReadCloser // ContentLength is the size in bytes (-1 if unknown) ContentLength int64 // ContentType is the MIME type of the response ContentType string // ETag is the entity tag for caching ETag string // CacheStatus indicates HIT or MISS CacheStatus CacheStatus // FetchedBytes is the number of bytes fetched from upstream (0 if cache hit) FetchedBytes int64 } // CacheStatus indicates whether the response was served from cache. type CacheStatus string // Cache status values for response headers. const ( CacheHit CacheStatus = "HIT" CacheMiss CacheStatus = "MISS" ) // Get retrieves a processed image, fetching and processing if necessary. // While its source URL is in the negative cache, a cached variant is still // served and a variant not in the cache is still made from a cached source; // only a request that needs the source fetched is refused. // // A cache hit opens the variant file and makes no database call: the cache // hands its access time to the goroutine that writes access times, without // waiting for it, and its hit is counted in memory. A variant file that // cannot be served, such as one whose first bytes are not those of an output // format, is a miss, and the variant is made again. func (p *Proxy) Get( ctx context.Context, req *imagerequest.Request, ) (*ImageResponse, error) { cacheKey := imagerequest.CacheKey(req) reader, size, contentType, err := p.cache.Variant(cacheKey) if err == nil { p.cache.IncrementStats(true) return &ImageResponse{ Content: reader, ContentLength: size, ContentType: contentType, CacheStatus: CacheHit, ETag: formatETag(cacheKey), }, nil } if !errors.Is(err, imgcache.ErrNotFound) { p.log.Warn("cached variant not served, making it again", "cache_key", cacheKey, "error", err) } // Cache miss - get the variant, processed once for all the requests that // miss it at the same time, then count this request's miss, also when it // failed or the request context has ended meanwhile response, err := p.processOrWait(ctx, req) p.cache.IncrementStats(false) if err != nil { return nil, err } response.CacheStatus = CacheMiss return response, nil } // WaitForProcessing waits until no image is being processed, or until ctx // ends, and returns how many images were still being processed then. func (p *Proxy) WaitForProcessing(ctx context.Context) int { return p.processor.WaitForProcessing(ctx) } // errPanicked is returned when processing a variant panicked. var errPanicked = errors.New("panic while processing image") // processOrWait returns the variant req asks for. The first of the requests // that miss a variant at the same time processes it, and singleflight hands // its result, or its error, to the others: they fetch nothing, read no source // and take no upstream connection or processing slot. The processing ignores // the first request's cancellation, so the others are still served if that // client goes away, but keeps its deadline. func (p *Proxy) processOrWait( ctx context.Context, req *imagerequest.Request, ) (*ImageResponse, error) { // A request that has already ended starts no processing if ctx.Err() != nil { return nil, ctx.Err() } cacheKey := imagerequest.CacheKey(req) // Closed when this request's own function runs, which singleflight does // only when no other request is processing the variant processing := make(chan struct{}) results := p.variantsInProgress.DoChan(string(cacheKey), func() (_ any, err error) { close(processing) // singleflight would raise a panic again in a goroutine of its // own, where no handler recovers it, and stop pixad. It is // reported through the Sentry hub that the Sentry middleware puts // on the request's context when sentry_dsn is set. defer func() { recovered := recover() if recovered != nil { p.log.Error("panic while processing image", "host", req.Source.Host, "path", req.Source.Path, "panic", recovered, "stack", string(debug.Stack())) if hub := sentry.GetHubFromContext(ctx); hub != nil { hub.RecoverWithContext(ctx, recovered) } err = fmt.Errorf("%w: %v", errPanicked, recovered) } }() processingCtx, cancel := withoutCancelKeepingDeadline(ctx) defer cancel() return p.processFromSourceOrFetch(processingCtx, req, cacheKey) }) var result singleflight.Result select { case result = <-results: case <-ctx.Done(): select { case <-processing: // This request is processing the variant: it waits for the // result, as every request did before misses were shared result = <-results default: // Another request is processing the variant, or this request's // function has not started yet; the processing goes on without it return nil, ctx.Err() } } if result.Err != nil { return nil, result.Err } variant, _ := result.Val.(*processedVariant) return &ImageResponse{ Content: io.NopCloser(bytes.NewReader(variant.data)), ContentLength: int64(len(variant.data)), ContentType: variant.contentType, FetchedBytes: variant.fetchedBytes, ETag: formatETag(cacheKey), }, nil } // withoutCancelKeepingDeadline returns ctx without its cancellation but with // its deadline, if it has one, and the func that releases the returned // context. func withoutCancelKeepingDeadline( ctx context.Context, ) (context.Context, context.CancelFunc) { deadline, hasDeadline := ctx.Deadline() if !hasDeadline { return context.WithoutCancel(ctx), func() {} } return context.WithDeadline(context.WithoutCancel(ctx), deadline) } // loadCachedSource opens src's cached source, without reading it, and // returns it with its size; nil if it is not in the cache, cannot be read, // is empty or exceeds maxResponseSize. func (p *Proxy) loadCachedSource( ctx context.Context, src imagerequest.Source, ) (io.ReadCloser, int64) { reader, size, err := p.cache.Source(ctx, src) if errors.Is(err, imgcache.ErrNotFound) { return nil, 0 } if err != nil { p.log.Warn("failed to load cached source, fetching", "error", err) return nil, 0 } p.log.Debug("using cached source", "source_key", src.Key()) if size > p.maxResponseSize { _ = reader.Close() p.log.Warn("cached source exceeds max response size, discarding", "source_key", src.Key(), "max_bytes", p.maxResponseSize, ) return nil, 0 } if size == 0 { _ = reader.Close() return nil, 0 } return reader, size } // processFromSourceOrFetch processes an image, using cached source content // if available. func (p *Proxy) processFromSourceOrFetch( ctx context.Context, req *imagerequest.Request, cacheKey imagerequest.VariantKey, ) (*processedVariant, error) { source, sourceSize := p.loadCachedSource(ctx, req.Source) // Fetch from upstream if we don't have source data or it's empty if source == nil { return p.fetchAndProcess(ctx, req, cacheKey) } defer func() { _ = source.Close() }() // Process using cached source; nothing was fetched from upstream. The // image processor reads the source only once it has a processing slot, // so a request waiting for one holds none of it in memory. return p.processAndStore(ctx, req, cacheKey, source, sourceSize) } // fetchAndProcess fetches from upstream, processes, and caches the result. // It counts the fetch with the bytes read from upstream, including when // reading the response or a later step fails. It fetches nothing while the // source URL is in the negative cache. func (p *Proxy) fetchAndProcess( ctx context.Context, req *imagerequest.Request, cacheKey imagerequest.VariantKey, ) (*processedVariant, error) { // Check negative cache - skip fetching for recently-failed URLs negHit, err := p.cache.Failure(ctx, req.Source) if err != nil { p.log.Warn("negative cache check failed", "error", err) } if negHit { p.log.Debug("negative cache hit", "host", req.Source.Host, "path", req.Source.Path, ) return nil, fmt.Errorf("%w: %w", httpfetcher.ErrUpstreamError, ErrNegativeCached) } // Fetch from upstream p.log.Debug("fetching from upstream", "host", req.Source.Host, "path", req.Source.Path, "query", req.Source.Query) fetchResult, err := p.fetcher.Fetch(ctx, req.Source) if err != nil { // Store negative cache for certain errors if isNegativeCacheable(err) { p.storeNegative(ctx, req) } return nil, fmt.Errorf("upstream fetch failed: %w", err) } // Closing the body frees the upstream connection. It is closed only // after processing, so the fetcher's connection limit also bounds the // fetched sources held in memory while their requests wait for a // processing slot. defer func() { _ = fetchResult.Content.Close() }() // Read and validate the source content sourceData, err := io.ReadAll(fetchResult.Content) fetchBytes := int64(len(sourceData)) // Counted also when the request context has ended meanwhile p.incrementUpstreamFetch(fetchBytes) if err != nil { return nil, fmt.Errorf("failed to read upstream response: %w", err) } // Calculate download bitrate var downloadRate string if fetchResult.FetchDurationMs > 0 { seconds := float64(fetchResult.FetchDurationMs) / 1000.0 //nolint:mnd // ms to seconds bitsPerSecond := float64(fetchBytes*8) / seconds //nolint:mnd // bytes to bits downloadRate = humanize.SI(bitsPerSecond, "bps") } // Log upstream fetch details p.log.Info("upstream fetched", "request_id", middleware.GetReqID(ctx), "host", req.Source.Host, "path", req.Source.Path, "bytes", fetchBytes, "fetch_ms", fetchResult.FetchDurationMs, "rate", downloadRate, "remote_addr", fetchResult.RemoteAddr, "http", fetchResult.HTTPVersion, "tls", fetchResult.TLSVersion, "cipher", fetchResult.TLSCipherSuite, ) // Validate magic bytes match content type. A body that does not is the // upstream's error, so it gets a negative cache entry, as an upstream // error status does. err = magic.ValidateMagicBytes(sourceData, fetchResult.ContentType) if err != nil { p.log.Warn("source refused", "request_id", middleware.GetReqID(ctx), "host", req.Source.Host, "path", req.Source.Path, "content_type", fetchResult.ContentType, "error", err) p.storeNegative(ctx, req) return nil, fmt.Errorf("content validation failed: %w", err) } // Store source content _, err = p.cache.PutSource(ctx, req.Source, bytes.NewReader(sourceData)) if err != nil { p.log.Warn("failed to store source content", "error", err) // Continue even if caching fails } return p.processAndStore( ctx, req, cacheKey, bytes.NewReader(sourceData), fetchBytes, ) } // incrementUpstreamFetch counts one upstream fetch that read fetchBytes bytes. // A fetch that read no bytes is not counted. func (p *Proxy) incrementUpstreamFetch(fetchBytes int64) { if fetchBytes <= 0 { return } p.upstreamFetches.Inc() p.upstreamFetchBytes.Add(float64(fetchBytes)) } // storeNegative stores a negative cache entry for req's source, whose fetch // failed, so the source is not fetched again until the entry expires. A // failure to store the entry is only logged. func (p *Proxy) storeNegative(ctx context.Context, req *imagerequest.Request) { err := p.cache.PutFailure(ctx, req.Source) if err != nil { p.log.Warn("failed to store negative cache entry", "host", req.Source.Host, "path", req.Source.Path, "error", err) } } // processedVariant is a variant as processAndStore made it. Each request that // shared its processing serves it through a reader of its own. type processedVariant struct { data []byte contentType string fetchedBytes int64 } // processAndStore processes the image read from source and stores the // result. func (p *Proxy) processAndStore( ctx context.Context, req *imagerequest.Request, cacheKey imagerequest.VariantKey, source io.Reader, fetchBytes int64, ) (*processedVariant, error) { // Process the image processStart := time.Now() // ctx has the deadline of the request doing the processing, which can // end while a request waiting for its image has time left processResult, err := p.processor.Process(ctx, source, &req.Transform) if errors.Is(err, context.DeadlineExceeded) { return nil, fmt.Errorf("%w: %w", ErrProcessingTimedOut, err) } if err != nil { return nil, fmt.Errorf("image processing failed: %w", err) } processDuration := time.Since(processStart) // Counted also when the request context has ended meanwhile p.transforms.Inc() // Read processed content processedData, err := io.ReadAll(processResult.Content) _ = processResult.Content.Close() if err != nil { return nil, fmt.Errorf("failed to read processed content: %w", err) } // Log conversion details outputSize := int64(len(processedData)) var sizePercent float64 if fetchBytes > 0 { //nolint:mnd // percentage calculation sizePercent = float64(outputSize) / float64(fetchBytes) * 100.0 } p.log.Info("image converted", "request_id", middleware.GetReqID(ctx), "host", req.Source.Host, "path", req.Source.Path, "src_format", processResult.InputFormat, "dst_format", req.Transform.Format, "src_bytes", fetchBytes, "dst_bytes", outputSize, "src_dimensions", fmt.Sprintf("%dx%d", processResult.InputWidth, processResult.InputHeight), "dst_dimensions", fmt.Sprintf("%dx%d", processResult.Width, processResult.Height), "size_ratio", fmt.Sprintf("%.1f%%", sizePercent), "convert_ms", processDuration.Milliseconds(), "quality", req.Transform.Quality, "fit", req.Transform.FitMode, ) // Store variant to cache err = p.cache.PutVariant(ctx, cacheKey, bytes.NewReader(processedData)) if err != nil { p.log.Warn("failed to store variant", "error", err) // Continue even if caching fails } return &processedVariant{ data: processedData, contentType: processResult.ContentType, fetchedBytes: fetchBytes, }, nil } // isNegativeCacheable returns true if the error should be cached. func isNegativeCacheable(err error) bool { return errors.Is(err, httpfetcher.ErrUpstreamError) } // etagHashLength is the number of hash characters to use for ETags. const etagHashLength = 16 // formatETag formats a VariantKey as a quoted ETag value. func formatETag(key imagerequest.VariantKey) string { hash := string(key) // Use first 16 characters of hash for a shorter but still unique ETag if len(hash) > etagHashLength { hash = hash[:etagHashLength] } return `"` + hash + `"` }