Log a line for requests the rack middleware blocks

Nidhey Indurkarrequested to merge
nindurkar/29874-log-blocked-requests into master

What does this MR do and why?

A request the labkit rack middleware blocks returns the 429 itself and never calls the app. No controller and no Grape endpoint runs, so lograge writes nothing at all for it. There is no record of which rule rejected anything, or who it rejected.

This writes one line from the middleware into the same auth log Rack::Attack's own throttle events already use, when a client first crosses a rule's limit and then only at twice, four times and eight times it.

Closes gitlab-com/gl-infra/production-engineering#29874 (closed).

The line

{
  "message": "Rate_Limit_Block",
  "status": 429,
  "matched": "throttle_unauthenticated_web",
  "rule": "unauthenticated_web",
  "limit": 500,
  "period_s": 60,
  "count": 501,
  "counted_by": { "ip": "198.51.100.7" },
  "applies_to": { "web_or_frontend": true, "requester_id": null, "git_http": false },
  "rate_limit_state": ["rack_request:unauthenticated_web:block"]
}

matched holds the throttle name, the same value and the same field Gitlab::Metrics::Subscribers::RackAttack already logs, so one json.matched query spans both stacks while they are both live. rate_limit_state reuses the exact limiter:rule:result strings the per-request field carries, so blocked, allowed and logged requests pivot together.

counted_by is the rule's counting bucket by value, so the line names the client that was blocked. count says how far past the limit it is.

applies_to answers "what kind of request does this reject" from the rule's own match conditions. Route regexes are elided to "(pattern)": repository_git_route_regex alone runs to kilobytes, and the rule name is enough to look the rest up.

No meta.caller_id or meta.feature_category. Those are pushed into ApplicationContext by the controller or Grape endpoint, and neither runs. Expect that gap rather than treating it as a bug.

When it fires

return false unless limit > 0 && count > limit
return true if count == limit + 1

multiple, over = count.divmod(limit)
over == 0 && multiple > 1 && (multiple & (multiple - 1)) == 0

On a 60-an-hour rule that is counts 61, 120, 240, 480, 960, so a client sending 10,000 requests an hour produces 8 lines.

Both bounds are load-bearing. Result::Info#count is a Float and a count_distinct rule can report a fractional one, and without them a count that truncates to the limit divides into a multiple of 1, reads as a doubling, and logs every blocked request. There is a spec for that case.

The trigger is the counter labkit already returned, so a blocked request costs no extra Redis call. Load on Redis in this path is what makes the limiter fail open and let more requests through during an attack.

Because the counter is per bucket, one client being blocked never silences another, and the line is per client without any bookkeeping.

Why not one line per blocked request

A line per block is unbounded in exactly the case it matters. Measured over 2026-09-22 06:00 to 2026-09-29 06:00 UTC on mimir-gitlab-gprd:

issue, 22 Sep measured
checks per second, all three limiters 185,000 110,000 to 200,000 at the daily peaks
blocks per second, 1h rate 335 13 to 590, seven-day mean 217
blocks per second, 5m rate 0 to 988

The checks figure counts every request three times, once per limiter, so the per-request ceiling is nearer 65,000 a second.

The block rate rises with the abuse the limiter exists to absorb, so the worst case is not the 988 above. Cloudflare and HAProxy absorb a volumetric flood before Rails, but not the case that actually happens: a client that is not attacking, does not back off, and sits over its limit for hours. INC-14504 was that shape.

Against today's behaviour the net is a reduction, because a request that is not blocked reaches the controller and lograge writes a line for it. A client sending 61 requests against a 60-an-hour rule trades one lograge line for one of these. A client sending 10,000 trades 9,940 lograge lines for 8.

Test plan

spec/lib/gitlab/middleware/labkit_rack_rate_limit_spec.rb. New examples cover the line's contents, regex elision, the first block, silence between doublings and the line at the next one, a fractional count at the limit, one line per client, and that the block path adds no Redis call of its own.

Review checklist

  • The trigger reads only the counter labkit already returned, no extra Redis call on the block path, pinned by a spec
  • Bounds are explicit against a fractional count, with a regression spec
  • counted_by exposes only values a rule already counts by, so no tokens and no raw query parameters
  • context is passed as an argument, not stored on the shared middleware instance
  • A raising logger cannot change the response
  • Teammate review before maintainer (ashs2, sankalp_gl, hardikgala approved)
  • Green pipeline on the final head
  • /lib/ and /spec/ maintainer approvals

References

MR acceptance checklist

Evaluate this MR against the MR acceptance checklist. It helps you analyze changes to reduce risks in quality, performance, reliability, security, and maintainability.

Edited by Nidhey Indurkar

Merge request reports