Skip to content

performance: High latency increase after upgrading from 1.10 to 1.11 #863

Description

@FUSAKLA

Hi after upgrade from 1.10 to 1.11 we were seeing huge latencies on pgw.

Unfortunately some of our pushgateways have up to 15k series and around 3 pushes per second.
(I know that's not the intended use-case… I'm not happy with it, but developers want it this way)

Anyway, the bigger the instance the bigger the latency impact was.
After investigation, it turned out the root cause is logging.
We bumped into this earlier when info level logs about inconsistent HELP of metrics caused the pgw to eat up lots of CPU so we increased log level to warn to mitigate this.

BUT after upgrading to 1.11 it turns out switch to promslog lead to a regression, that the CPU is wasted even if the log level is warn.

Pprof with --log-level=warn 👇 See the log/slog.(*Logger).Info even on warn log level

File: pushgateway
Build ID: c1b7e44f1f1913a38626129896731b8cadd7e49e
Type: cpu
Time: 2026-08-13 18:16:55 CEST
Duration: 120s, Total samples = 16.89s (14.07%)
Showing nodes accounting for 13.49s, 79.87% of 16.89s total
Dropped 353 nodes (cum <= 0.08s)
      flat  flat%   sum%        cum   cum%
         0     0%     0%     11.06s 65.48%  github.com/prometheus/client_golang/prometheus.Gatherers.Gather
         0     0%     0%     10.90s 64.54%  github.com/prometheus/pushgateway/storage.(*DiskMetricStore).checkWriteRequest
         0     0%     0%     10.90s 64.54%  github.com/prometheus/pushgateway/storage.(*DiskMetricStore).loop
         0     0%     0%     10.77s 63.77%  github.com/prometheus/client_golang/prometheus.GathererFunc.Gather
         0     0%     0%     10.77s 63.77%  github.com/prometheus/pushgateway/storage.(*DiskMetricStore).GetMetricFamilies
         0     0%     0%     10.75s 63.65%  github.com/prometheus/pushgateway/storage.(*DiskMetricStore).checkWriteRequest.func2
         0     0%     0%     10.72s 63.47%  log/slog.(*Logger).Info (inline)
         0     0%     0%     10.72s 63.47%  log/slog.(*Logger).log
         0     0%     0%     10.72s 63.47%  log/slog.(*TextHandler).Handle
         0     0%     0%     10.72s 63.47%  log/slog.(*commonHandler).handle
         0     0%     0%     10.70s 63.35%  log/slog.(*handleState).appendAttr
         0     0%     0%     10.70s 63.35%  log/slog.(*handleState).appendValue
         0     0%     0%     10.70s 63.35%  log/slog.appendTextValue
         0     0%     0%     10.69s 63.29%  log/slog.(*handleState).appendNonBuiltIns
         0     0%     0%     10.69s 63.29%  log/slog.(*handleState).appendNonBuiltIns.func1 (inline)
         0     0%     0%     10.69s 63.29%  log/slog.Record.Attrs (inline)
         0     0%     0%      8.15s 48.25%  fmt.Sprintf

After digging deeper it turned out that the promslog.NopLogger actually does serialize the log message and after that discards it, so solution would be dropped it right away.

The main pain point is its usage in the DiskMetricStore and logging the inconsistent help strings

logger: promslog.NewNopLogger(),

dms.logger.Info("metric families inconsistent help strings", "err", "Metric families have inconsistent help strings. The latter will have priority. This is bad. Fix your pushed metrics!", "new", mf, "old", existingMF)

I created a PR in the prometheus/common with this fix prometheus/common#960

if accepted all that would be needed on the pgw side is to update the dependency, creating the issue more like a tracker/reminder

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions