Export cache, eviction, upstream and transform metrics (closes #85)
check / check (push) Canceled after 0s
check / check (push) Canceled after 0s
New pixa_ metrics, none with labels: - source cache hits and misses, counted once per variant made or checked - cache usage and limit gauges; usage is set each time eviction reads it - eviction count and bytes, from the size_bytes the deleted row returns - upstream fetch duration histogram and fetch error counter - transform duration histogram and an in-progress gauge, both including the wait for a processing slot Removing a damaged file during reconciliation is not counted as an eviction. README lists every metric; the metrics config comment now says the pixa_ metrics are measured whether or not /metrics is served. Model: opus-5-5
This commit is contained in:
1 parent
fe5bf393b1
commit
7014d88956
9 files changed
+314
-113
No files matched your search
@@ -37,11 +37,15 @@ type Proxy struct {
|
||||
// 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
|
||||
// The metrics of upstream fetches and transforms, made and registered by
|
||||
// New. They are kept in memory, so updating one waits for nothing.
|
||||
upstreamFetches prometheus.Counter
|
||||
upstreamFetchBytes prometheus.Counter
|
||||
upstreamFetchDurations prometheus.Histogram
|
||||
upstreamFetchErrors prometheus.Counter
|
||||
transforms prometheus.Counter
|
||||
transformDurations prometheus.Histogram
|
||||
transformsInProgress prometheus.Gauge
|
||||
}
|
||||
|
||||
// Config holds the proxy's configuration.
|
||||
@@ -62,9 +66,9 @@ type Config struct {
|
||||
// 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
|
||||
// New creates a new image proxy and registers its metrics on
|
||||
// metricsRegistry. pixad passes Prometheus' default registry, the one
|
||||
// /metrics serves. It fails when metricsRegistry already holds counters of
|
||||
// /metrics serves. It fails when metricsRegistry already holds metrics of
|
||||
// the same names.
|
||||
func New(
|
||||
cfg *Config, metricsRegistry prometheus.Registerer,
|
||||
@@ -99,18 +103,39 @@ func New(
|
||||
Name: "pixa_upstream_fetch_bytes_total",
|
||||
Help: "Bytes read from upstream by fetches of source images.",
|
||||
}),
|
||||
upstreamFetchDurations: prometheus.NewHistogram(prometheus.HistogramOpts{
|
||||
Name: "pixa_upstream_fetch_duration_seconds",
|
||||
Help: "Duration of the fetches pixa_upstream_fetches_total counts, " +
|
||||
"until the response's last byte.",
|
||||
}),
|
||||
upstreamFetchErrors: prometheus.NewCounter(prometheus.CounterOpts{
|
||||
Name: "pixa_upstream_fetch_errors_total",
|
||||
Help: "Fetches of a source image from upstream that failed, " +
|
||||
"before or while reading the response.",
|
||||
}),
|
||||
transforms: prometheus.NewCounter(prometheus.CounterOpts{
|
||||
Name: "pixa_transforms_total",
|
||||
Help: "Images the image processor transformed.",
|
||||
}),
|
||||
transformDurations: prometheus.NewHistogram(prometheus.HistogramOpts{
|
||||
Name: "pixa_transform_duration_seconds",
|
||||
Help: "Duration of the transforms pixa_transforms_total counts, " +
|
||||
"waiting for a processing slot included.",
|
||||
}),
|
||||
transformsInProgress: prometheus.NewGauge(prometheus.GaugeOpts{
|
||||
Name: "pixa_transforms_in_progress",
|
||||
Help: "Images being transformed or waiting for a processing slot.",
|
||||
}),
|
||||
}
|
||||
|
||||
for _, counter := range []prometheus.Counter{
|
||||
p.upstreamFetches, p.upstreamFetchBytes, p.transforms,
|
||||
for _, metric := range []prometheus.Collector{
|
||||
p.upstreamFetches, p.upstreamFetchBytes, p.upstreamFetchDurations,
|
||||
p.upstreamFetchErrors, p.transforms, p.transformDurations,
|
||||
p.transformsInProgress,
|
||||
} {
|
||||
err = metricsRegistry.Register(counter)
|
||||
err = metricsRegistry.Register(metric)
|
||||
if err != nil {
|
||||
return nil, fmt.Errorf("failed to register the proxy's counters: %w", err)
|
||||
return nil, fmt.Errorf("failed to register the proxy's metrics: %w", err)
|
||||
}
|
||||
}
|
||||
|
||||
@@ -341,7 +366,8 @@ func (p *Proxy) loadCachedSource(
|
||||
}
|
||||
|
||||
// processFromSourceOrFetch makes the variant req asks for, from the cached
|
||||
// source when there is one and from a fetched source otherwise.
|
||||
// source when there is one and from a fetched source otherwise. It counts
|
||||
// whether the source was in the cache.
|
||||
//
|
||||
// A cached source last checked with upstream CacheTTL or more ago is checked
|
||||
// first: upstream is asked to send it only if it changed since. When it
|
||||
@@ -362,9 +388,13 @@ func (p *Proxy) processFromSourceOrFetch(
|
||||
p.log.Warn("failed to look up cached source, fetching", "error", err)
|
||||
}
|
||||
|
||||
p.cache.IncrementSourceStats(false)
|
||||
|
||||
return p.fetchAndProcess(ctx, req, cacheKey)
|
||||
}
|
||||
|
||||
p.cache.IncrementSourceStats(true)
|
||||
|
||||
if p.cache.Stale(cached.CheckedAt) {
|
||||
fetched, err := p.fetchSource(ctx, req, cached.ETag, cached.LastModified)
|
||||
|
||||
@@ -581,36 +611,32 @@ type fetchedSource struct {
|
||||
// fetchSource fetches req's source from upstream and stores it in the cache.
|
||||
// A non-empty ifNoneMatch or ifModifiedSince asks upstream to send the source
|
||||
// only if it changed since; errSourceNotModified says it did not. 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. The caller closes the returned response.
|
||||
// the fetch with the bytes read from upstream and its duration, including
|
||||
// when reading the response or a later step fails, and counts a fetch that
|
||||
// fails or whose response cannot be read as an upstream fetch error. It
|
||||
// fetches nothing while the source URL is in the negative cache. The caller
|
||||
// closes the returned response.
|
||||
func (p *Proxy) fetchSource(
|
||||
ctx context.Context,
|
||||
req *imagerequest.Request,
|
||||
ifNoneMatch, ifModifiedSince string,
|
||||
) (*fetchedSource, error) {
|
||||
// Check negative cache - skip fetching for recently-failed URLs
|
||||
negHit, err := p.cache.Failure(ctx, req.Source)
|
||||
err := p.refuseNegativeCached(ctx, req)
|
||||
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)
|
||||
return nil, err
|
||||
}
|
||||
|
||||
// Fetch from upstream
|
||||
p.log.Debug("fetching from upstream", "host", req.Source.Host,
|
||||
"path", req.Source.Path, "query", req.Source.Query)
|
||||
|
||||
fetchStart := time.Now()
|
||||
|
||||
fetchResult, err := p.fetcher.Fetch(ctx, req.Source,
|
||||
ifNoneMatch, ifModifiedSince)
|
||||
if err != nil {
|
||||
p.upstreamFetchErrors.Inc()
|
||||
|
||||
// Store negative cache for certain errors
|
||||
if isNegativeCacheable(err) {
|
||||
p.storeNegative(ctx, req)
|
||||
@@ -634,9 +660,11 @@ func (p *Proxy) fetchSource(
|
||||
fetchBytes := int64(len(sourceData))
|
||||
|
||||
// Counted also when the request context has ended meanwhile
|
||||
p.incrementUpstreamFetch(fetchBytes)
|
||||
p.incrementUpstreamFetch(fetchBytes, time.Since(fetchStart))
|
||||
|
||||
if err != nil {
|
||||
p.upstreamFetchErrors.Inc()
|
||||
|
||||
_ = fetchResult.Content.Close()
|
||||
|
||||
return nil, fmt.Errorf("failed to read upstream response: %w", err)
|
||||
@@ -677,6 +705,29 @@ func (p *Proxy) fetchSource(
|
||||
}, nil
|
||||
}
|
||||
|
||||
// refuseNegativeCached returns an error wrapping ErrNegativeCached while
|
||||
// req's source URL is in the negative cache, and nil otherwise. A failure to
|
||||
// read the negative cache is only logged, and returns nil.
|
||||
func (p *Proxy) refuseNegativeCached(
|
||||
ctx context.Context, req *imagerequest.Request,
|
||||
) error {
|
||||
negHit, err := p.cache.Failure(ctx, req.Source)
|
||||
if err != nil {
|
||||
p.log.Warn("negative cache check failed", "error", err)
|
||||
}
|
||||
|
||||
if !negHit {
|
||||
return nil
|
||||
}
|
||||
|
||||
p.log.Debug("negative cache hit",
|
||||
"host", req.Source.Host,
|
||||
"path", req.Source.Path,
|
||||
)
|
||||
|
||||
return fmt.Errorf("%w: %w", httpfetcher.ErrUpstreamError, ErrNegativeCached)
|
||||
}
|
||||
|
||||
// fetchedSourceInfo returns what the cache keeps about a source upstream
|
||||
// just sent: fetched and checked now, with the ETag and Last-Modified
|
||||
// headers of fetchResult.
|
||||
@@ -722,15 +773,16 @@ func (p *Proxy) logUpstreamFetch(
|
||||
)
|
||||
}
|
||||
|
||||
// incrementUpstreamFetch counts one upstream fetch that read fetchBytes bytes.
|
||||
// A fetch that read no bytes is not counted.
|
||||
func (p *Proxy) incrementUpstreamFetch(fetchBytes int64) {
|
||||
// incrementUpstreamFetch counts one upstream fetch that read fetchBytes bytes
|
||||
// and took duration. A fetch that read no bytes is not counted.
|
||||
func (p *Proxy) incrementUpstreamFetch(fetchBytes int64, duration time.Duration) {
|
||||
if fetchBytes <= 0 {
|
||||
return
|
||||
}
|
||||
|
||||
p.upstreamFetches.Inc()
|
||||
p.upstreamFetchBytes.Add(float64(fetchBytes))
|
||||
p.upstreamFetchDurations.Observe(duration.Seconds())
|
||||
}
|
||||
|
||||
// storeNegative stores a negative cache entry for req's source, whose fetch
|
||||
@@ -772,8 +824,7 @@ func (p *Proxy) processAndStore(
|
||||
|
||||
// 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, sourceFormat,
|
||||
&req.Transform)
|
||||
processResult, err := p.transform(ctx, source, sourceFormat, &req.Transform)
|
||||
if errors.Is(err, context.DeadlineExceeded) {
|
||||
return nil, fmt.Errorf("%w: %w", ErrProcessingTimedOut, err)
|
||||
}
|
||||
@@ -786,6 +837,7 @@ func (p *Proxy) processAndStore(
|
||||
|
||||
// Counted also when the request context has ended meanwhile
|
||||
p.transforms.Inc()
|
||||
p.transformDurations.Observe(processDuration.Seconds())
|
||||
|
||||
// Read processed content
|
||||
processedData, err := io.ReadAll(processResult.Content)
|
||||
@@ -838,6 +890,21 @@ func (p *Proxy) processAndStore(
|
||||
}, nil
|
||||
}
|
||||
|
||||
// transform has the image processor transform the image read from source
|
||||
// as requested says, and counts it in pixa_transforms_in_progress until the
|
||||
// processor returns or panics.
|
||||
func (p *Proxy) transform(
|
||||
ctx context.Context,
|
||||
source io.Reader,
|
||||
sourceFormat imagerequest.Format,
|
||||
requested *imagerequest.Transform,
|
||||
) (*imageprocessor.Result, error) {
|
||||
p.transformsInProgress.Inc()
|
||||
defer p.transformsInProgress.Dec()
|
||||
|
||||
return p.processor.Process(ctx, source, sourceFormat, requested)
|
||||
}
|
||||
|
||||
// isNegativeCacheable returns true if the error should be cached.
|
||||
func isNegativeCacheable(err error) bool {
|
||||
return errors.Is(err, httpfetcher.ErrUpstreamError)
|
||||
|
||||
Reference in new issue
Block a user