Commit 36a29c44 authored by Ashwin S's avatar Ashwin S
Browse files

Applying the Metric Error logging to all methods

parent a7a6a159

lib/labkit/rate_limit/evaluator.rb

+9 −0
Original line number Diff line number Diff line
@@ -71,6 +71,7 @@ module Labkit 
        @rules  = rules

        @redis  = redis

        @logger = logger

        @metrics_failure_logged = false

      end



      def check(identifier, cost: 1, rule_context: nil)
@@ -394,6 +395,8 @@ module Labkit 
          { rate_limiter: @name, rule: evaluation.rule.name },

          evaluation.info.resolved_period

        )

      rescue StandardError => e

        log_metrics_failure(e)

      end



      # An exceeded :log rule reports "log" rather than the "allow" the caller
@@ -413,6 +416,8 @@ module Labkit 
        )

        # 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)

      end



      # Deprecated dual emission - remove together with Metrics.calls_total.
@@ -422,6 +427,8 @@ module Labkit 
          rule: "unmatched",

          action: "allow"

        )

      rescue StandardError => e

        log_metrics_failure(e)

      end



      def report_check_metrics(result)
@@ -444,6 +451,8 @@ module Labkit 
      # 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

spec/labkit/rate_limit/evaluator_spec.rb

+31 −11
Original line number Diff line number Diff line
@@ -623,24 +623,23 @@ RSpec.describe Labkit::RateLimit::Evaluator do 
      described_class.new(name: "rack_request", rules: rules, redis: redis, logger: logger).check(id)

    end



    it "logs a nil rule when the error is raised with no rule in flight" do

    it "completes the check normally when post-loop metric emission fails" do

      logger = instance_double(Labkit::Logging::JsonLogger)

      # The allow absorbs the rate_limit_metrics_error warn from the rescue's

      # own swallowed checks_total failure.

      allow(logger).to receive(:warn)

      expect(logger).to receive(:warn).with(hash_including(rule: nil))



      # The unmatched calls_total emission and report_check_metrics both run

      # after the loop, so the raise lands where no rule can be blamed. The

      # rescue's own checks_total emission swallows the same raise.

      # errors_total is left alone: the rescue still uses it.

      # Only the once-per-evaluator 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"))

        .once



      allow(Labkit::RateLimit::Metrics).to receive(:calls_total).and_raise("metrics down")

      allow(Labkit::RateLimit::Metrics).to receive(:checks_total).and_raise("metrics down")



      rule = make_rule(name: "other_rule", match: { user: 999 })

      result = described_class.new(name: "rack_request", rules: [rule], redis: redis, logger: logger).check(identifier)



      expect(result.error?).to be(true)

      expect(result.error?).to be(false)

      expect(result.matched?).to be(false)

      expect(result.action).to eq(:allow)

    end



    it "logs the rule whose peek raised" do
@@ -821,6 +820,27 @@ RSpec.describe Labkit::RateLimit::Evaluator do 
      expect(result.error?).to be(false)

    end



    it "does not change a block verdict when the rule evaluation emission fails" do

      allow(Labkit::RateLimit::Metrics).to receive(:rule_evaluations_total).and_raise("metrics down")



      rule = make_rule(name: "block_rule", limit: 1)

      result = evaluator(rules: [rule]).check(identifier, cost: 2)



      expect(result.action).to eq(:block)

      expect(result.error?).to be(false)

    end



    it "keeps a matched :skip verdict when the skip emission fails" do

      allow(Labkit::RateLimit::Metrics).to receive(:rule_evaluations_total).and_raise("metrics down")



      rule = make_rule(name: "bypass", action: :skip)

      result = evaluator(rules: [rule]).check(identifier)



      expect(result.matched?).to be(true)

      expect(result.rule).to eq(rule)

      expect(result.error?).to be(false)

    end



    it "logs a metrics failure once per evaluator, not per check" do

      allow(Labkit::RateLimit::Metrics).to receive(:checks_total).and_raise("metrics down")