Commit 9598a1e5 authored by Ashwin S's avatar Ashwin S
Browse files

refactor(rate_limit): consolidate metric emission per review

parent 36a29c44
Loading
Loading
Loading
Loading
+2 −2
Original line number Diff line number Diff line
@@ -414,8 +414,8 @@ metric, or logs only.

Metric emission itself is best-effort: a failure in the metrics stack never
alters the verdict or breaks fail-open, and is logged at WARN with
`error_type: "rate_limit_metrics_error"` (once per evaluator per process, to
avoid flooding).
`error_type: "rate_limit_metrics_error"` (once per process, to avoid
flooding).

## Metrics

+42 −69
Original line number Diff line number Diff line
@@ -71,24 +71,21 @@ module Labkit
        @rules  = rules
        @redis  = redis
        @logger = logger
        @metrics_failure_logged = false
      end

      def check(identifier, cost: 1, rule_context: nil)
        cursor = RuleCursor.new
        result = check_rules(identifier, cost, rule_context, cursor)

        # Setting to nil as a raise from the per-check emission belongs to no rule
        cursor.rule = nil
        report_check_metrics(result)
        result
      rescue StandardError => e
        # Intentionally broad: fail-open applies to any unexpected error (network,
        # timeout, OOM) not only Redis protocol errors.
        report_error_metrics
        report_check_metrics(Result.error)
        log_error(e, identifier, cursor.rule)
        Result.error
        result = Result.error
      ensure
        # StandardError-safe emission, so it cannot mask a propagating error.
        # result is nil when a non-StandardError unwinds: emit nothing then.
        report_check_metrics(result) if result
      end

      # Read-without-increment counterpart to {#check}. Same matching and Result
@@ -169,6 +166,12 @@ module Labkit

        report_unmatched_metrics unless result.matched?
        result
      rescue StandardError => e # binds e for the ensure
        raise
      ensure
        # Keep the rule attributed while an exception unwinds; clear it on
        # every normal exit (early returns included).
        cursor.rule = nil unless e
      end

      # Mirror of check_rules without metrics or writes. :log rules are read
@@ -192,9 +195,11 @@ module Labkit
          return result if result.block?
        end

        cursor.rule = nil

        result
      rescue StandardError => e # binds e for the ensure
        raise
      ensure
        cursor.rule = nil unless e
      end

      def rule_matches?(rule, identifier)
@@ -353,6 +358,7 @@ module Labkit
      # loop reached one, or after it finished - so the field is logged as null
      # rather than omitted, the same way identifier is. A named rule is the rule
      # whose match or evaluation raised.
      # Never raises: a logging failure must not break fail-open.
      def log_error(error, identifier, rule = nil)
        @logger.warn(
          name: @name,
@@ -362,6 +368,8 @@ module Labkit
          Labkit::Fields::ERROR_MESSAGE => error.message,
          identifier: identifier&.to_h
        )
      rescue StandardError
        nil
      end

      def log_missing_count_distinct(rule, identifier)
@@ -375,28 +383,21 @@ module Labkit
      end

      def report_evaluation_metrics(evaluation)
        Metrics.rule_evaluations_total.increment(
          rate_limiter: @name,
          rule: evaluation.rule.name,
          action: evaluation.rule.action.to_s,
          result: evaluation_result(evaluation)
        rule_labels = { rate_limiter: @name, rule: evaluation.rule.name }

        Metrics.safe_increment(
          :rule_evaluations_total,
          rule_labels.merge(action: evaluation.rule.action.to_s, result: evaluation_result(evaluation)),
          logger: @logger
        )
        # Deprecated dual emission - remove together with Metrics.calls_total.
        Metrics.calls_total.increment(
          rate_limiter: @name,
          rule: evaluation.rule.name,
          action: (evaluation.exceeded? ? evaluation.rule.action : :allow).to_s
        )
        Metrics.limit_gauge.set(
          { rate_limiter: @name, rule: evaluation.rule.name },
          evaluation.info.resolved_limit
        Metrics.safe_increment(
          :calls_total,
          rule_labels.merge(action: (evaluation.exceeded? ? evaluation.rule.action : :allow).to_s),
          logger: @logger
        )
        Metrics.period_gauge.set(
          { rate_limiter: @name, rule: evaluation.rule.name },
          evaluation.info.resolved_period
        )
      rescue StandardError => e
        log_metrics_failure(e)
        Metrics.safe_set(:limit_gauge, rule_labels, evaluation.info.resolved_limit, logger: @logger)
        Metrics.safe_set(:period_gauge, rule_labels, evaluation.info.resolved_period, logger: @logger)
      end

      # An exceeded :log rule reports "log" rather than the "allow" the caller
@@ -408,63 +409,35 @@ module Labkit
      end

      def report_skipped_metrics(rule)
        Metrics.rule_evaluations_total.increment(
          rate_limiter: @name,
          rule: rule.name,
          action: "skip",
          result: "skip"
        Metrics.safe_increment(
          :rule_evaluations_total,
          { rate_limiter: @name, rule: rule.name, action: "skip", result: "skip" },
          logger: @logger
        )
        # Deprecated dual emission - remove together with Metrics.calls_total.
        Metrics.calls_total.increment(rate_limiter: @name, rule: rule.name, action: "skip")
      rescue StandardError => e
        log_metrics_failure(e)
        Metrics.safe_increment(:calls_total, { rate_limiter: @name, rule: rule.name, action: "skip" }, logger: @logger)
      end

      # Deprecated dual emission - remove together with Metrics.calls_total.
      def report_unmatched_metrics
        Metrics.calls_total.increment(
          rate_limiter: @name,
          rule: "unmatched",
          action: "allow"
        )
      rescue StandardError => e
        log_metrics_failure(e)
        Metrics.safe_increment(:calls_total, { rate_limiter: @name, rule: "unmatched", action: "allow" }, logger: @logger)
      end

      def report_check_metrics(result)
        Metrics.checks_total.increment(
        Metrics.safe_increment(
          :checks_total,
          {
            rate_limiter: @name,
            action: result.action.to_s,
            matched: result.matched?.to_s,
            error: (result.error? || result.degraded?).to_s
          },
          logger: @logger
        )
      rescue StandardError => e
        log_metrics_failure(e)
      end

      def report_error_metrics
        Metrics.errors_total.increment(rate_limiter: @name)
      rescue StandardError => e
        log_metrics_failure(e)
      end

      # Logged once per evaluator instance so a persistently broken metrics
      # stack stays visible without flooding the hot path, and never raises
      # (callers rescue precisely to protect the verdict and fail-open).
      # The once-latch is deliberately lock-free: concurrent first failures
      # may each log a duplicate warn, which is harmless.
      def log_metrics_failure(error)
        return if @metrics_failure_logged

        @metrics_failure_logged = true
        @logger.warn(
          name: @name,
          Labkit::Fields::ERROR_TYPE => "rate_limit_metrics_error",
          Labkit::Fields::CLASS_NAME => error.class.to_s,
          Labkit::Fields::ERROR_MESSAGE => error.message
        )
      rescue StandardError
        nil
        Metrics.safe_increment(:errors_total, { rate_limiter: @name }, logger: @logger)
      end
    end
  end
+37 −0
Original line number Diff line number Diff line
# frozen_string_literal: true

require "concurrent-ruby"

module Labkit
  module RateLimit
    module Metrics
      # Process-wide once-latch for log_failure; specs reset via make_false.
      FAILURE_LOGGED = Concurrent::AtomicBoolean.new(false)

      module_function

      # Metric emission must never affect the caller's outcome. Resolving the
      # metric by name keeps a raising getter inside the rescue.
      def safe_increment(counter, labels, logger: nil)
        public_send(counter).increment(**labels) # rubocop:disable GitlabSecurity/PublicSend
      rescue StandardError => e
        log_failure(e, counter, labels, logger)
      end

      # Gauge counterpart of safe_increment.
      def safe_set(gauge, labels, value, logger: nil)
        public_send(gauge).set(labels, value) # rubocop:disable GitlabSecurity/PublicSend
      rescue StandardError => e
        log_failure(e, gauge, labels, logger)
      end

      # make_true returns true only for the flipping caller, so exactly one
      # warn per process. Never raises - a raise here would defeat the
      # callers' rescues.
      def log_failure(error, metric, labels, logger)
        return unless logger && FAILURE_LOGGED.make_true

        logger.warn(
          name: labels[:rate_limiter],
          metric: metric.to_s,
          Labkit::Fields::ERROR_TYPE => "rate_limit_metrics_error",
          Labkit::Fields::CLASS_NAME => error.class.to_s,
          Labkit::Fields::ERROR_MESSAGE => error.message
        )
      rescue StandardError
        nil
      end

      # Emitted exactly once per #check call, including calls that fail open;
      # summing by rate_limiter gives the request rate through the limiter.
      def checks_total
+7 −4
Original line number Diff line number Diff line
@@ -31,6 +31,7 @@ RSpec.describe Labkit::RateLimit::Evaluator do
  before do
    stub_env("RAILS_ENV", "test")
    TestRedis.reset!
    Labkit::RateLimit::Metrics::FAILURE_LOGGED.make_false
  end

  describe "Redis key format" do
@@ -625,7 +626,7 @@ RSpec.describe Labkit::RateLimit::Evaluator do

    it "completes the check normally when post-loop metric emission fails" do
      logger = instance_double(Labkit::Logging::JsonLogger)
      # Only the once-per-evaluator rate_limit_metrics_error warn is expected;
      # Only the once-per-process rate_limit_metrics_error warn is expected;
      # no rate_limit_error, because the metrics failure is swallowed.
      expect(logger).to receive(:warn)
        .with(hash_including(Labkit::Fields::ERROR_TYPE => "rate_limit_metrics_error"))
@@ -841,7 +842,7 @@ RSpec.describe Labkit::RateLimit::Evaluator do
      expect(result.error?).to be(false)
    end

    it "logs a metrics failure once per evaluator, not per check" do
    it "logs a metrics failure once per process, not per evaluator or check" do
      allow(Labkit::RateLimit::Metrics).to receive(:checks_total).and_raise("metrics down")

      logger = instance_double(Labkit::Logging::JsonLogger)
@@ -850,8 +851,10 @@ RSpec.describe Labkit::RateLimit::Evaluator do
        .once

      rule = make_rule(name: "api_rule", limit: 100, period: 60)
      ev = described_class.new(name: "rack_request", rules: [rule], redis: redis, logger: logger)
      2.times { ev.check(identifier) }
      first = described_class.new(name: "rack_request", rules: [rule], redis: redis, logger: logger)
      second = described_class.new(name: "web_request", rules: [rule], redis: redis, logger: logger)
      2.times { first.check(identifier) }
      second.check(identifier)
    end

    it "fails open without raising when errors_total emission itself fails" do
+43 −0
Original line number Diff line number Diff line
@@ -4,6 +4,49 @@ require "spec_helper"
require "prometheus/client"

RSpec.describe Labkit::RateLimit::Metrics, :with_metrics_config do
  before do
    described_class::FAILURE_LOGGED.make_false
  end

  describe ".safe_increment" do
    it "increments the counter" do
      described_class.safe_increment(:errors_total, { rate_limiter: "rack_request" })

      expect(described_class.errors_total.get(rate_limiter: "rack_request")).to eq(1.0)
    end

    it "swallows metric errors and logs once per process" do
      allow(described_class).to receive(:errors_total).and_raise("metrics down")

      logger = instance_double(Labkit::Logging::JsonLogger)
      expect(logger).to receive(:warn)
        .with(hash_including(Labkit::Fields::ERROR_TYPE => "rate_limit_metrics_error", name: "rack_request"))
        .once

      2.times { described_class.safe_increment(:errors_total, { rate_limiter: "rack_request" }, logger: logger) }
    end

    it "does not raise without a logger" do
      allow(described_class).to receive(:errors_total).and_raise("metrics down")

      expect { described_class.safe_increment(:errors_total, { rate_limiter: "x" }) }.not_to raise_error
    end
  end

  describe ".safe_set" do
    it "sets the gauge" do
      described_class.safe_set(:limit_gauge, { rate_limiter: "rack_request", rule: "r" }, 42)

      expect(described_class.limit_gauge.get(rate_limiter: "rack_request", rule: "r")).to eq(42.0)
    end

    it "swallows metric errors" do
      allow(described_class).to receive(:limit_gauge).and_raise("metrics down")

      expect { described_class.safe_set(:limit_gauge, { rate_limiter: "x", rule: "r" }, 1) }.not_to raise_error
    end
  end

  describe ".checks_total" do
    it "returns a Prometheus counter" do
      expect(described_class.checks_total).to be_a(Prometheus::Client::Counter)