Commit bfe84cb4 authored by Sam Wiskow's avatar Sam Wiskow
Browse files

refactor(evaluator): delegate logging to Labkit::Logging::JsonLogger

Replace manual JSON.generate calls with JsonLogger, which handles
serialisation, severity, and structured field merging. Removes
require "json" and require "logger" from evaluator.

Update specs: logger now receives a Hash (not a JSON string), so
matchers updated from a_string_including to hash_including, and
block-based assertions updated to check symbol-keyed Hash fields.
parent 3449cc41
Loading
Loading
Loading
Loading
+10 −20
Original line number Diff line number Diff line
# frozen_string_literal: true

require "json"
require "logger"
require "openssl"
require "labkit/logging/json_logger"

module Labkit
  module RateLimit
    # Evaluator contains the core rule-matching + Redis counter logic.
    # @api private
    class Evaluator
      KNOWN_CHARACTERISTICS = [:user, :ip, :namespace, :plan, :endpoint].freeze
      KNOWN_ACTIONS = [:block, :log].freeze
@@ -57,12 +55,11 @@ module Labkit
        raise ArgumentError, "Invalid call_site: #{@call_site.inspect}. Must match /\\A[a-z0-9_]+\\z/" if dev_or_test?

        sanitized = @call_site.gsub(/[^a-z0-9_]/, "_")
        @logger.warn(JSON.generate(
          severity: "WARN",
        @logger.warn(
          message: "rate_limit_invalid_call_site",
          call_site: @call_site,
          sanitized: sanitized
        ))
        )
        @call_site = sanitized
      end

@@ -94,11 +91,10 @@ module Labkit
        unless KNOWN_CHARACTERISTICS.include?(char)
          raise ArgumentError, "Unknown characteristic: #{char.inspect}. Known: #{KNOWN_CHARACTERISTICS.inspect}" if dev_or_test?

          @logger.warn(JSON.generate(
            severity: "WARN",
          @logger.warn(
            message: "rate_limit_unknown_characteristic",
            characteristic: char
          ))
          )
          return UNKNOWN_SENTINEL
        end

@@ -131,8 +127,7 @@ module Labkit
      end

      def log_rule(rule, index, count, redis_key, exceeded)
        entry = {
          severity: "INFO",
        @logger.info(
          message: "rate_limit_check",
          call_site: @call_site,
          rule_index: index,
@@ -144,19 +139,16 @@ module Labkit
          exceeded: exceeded,
          identifier: @identifier.to_h,
          redis_key: redis_key
        }
        @logger.info(JSON.generate(entry))
        )
      end

      def log_evaluate_error(error)
        entry = {
          severity: "WARN",
        @logger.warn(
          message: "rate_limit_redis_error",
          call_site: @call_site,
          error: error.class.to_s,
          result: "allow"
        }
        @logger.warn(JSON.generate(entry))
        )
      end

      def dev_or_test?
@@ -168,9 +160,7 @@ module Labkit
      end

      def build_default_logger
        logger = Logger.new($stdout)
        logger.formatter = proc { |_sev, _dt, _prog, msg| "#{msg}\n" }
        logger
        Labkit::Logging::JsonLogger.new($stdout)
      end
    end
  end
+14 −16
Original line number Diff line number Diff line
@@ -98,7 +98,7 @@ RSpec.describe Labkit::RateLimit::Evaluator do
      allow(redis).to receive(:incr).and_return(1)
      allow(redis).to receive(:expire)

      expect(logger).to receive(:warn).with(a_string_including("rate_limit_invalid_call_site"))
      expect(logger).to receive(:warn).with(hash_including(message: "rate_limit_invalid_call_site"))
      evaluator(call_site: "bad:site", rules: [rule]).evaluate
    end
  end
@@ -118,7 +118,7 @@ RSpec.describe Labkit::RateLimit::Evaluator do
        .with("labkit:rl:rack_request:0:unknown_thing:unknown_characteristic")
        .and_return(1)
      expect(redis).to receive(:expire)
      expect(logger).to receive(:warn).with(a_string_including("rate_limit_unknown_characteristic"))
      expect(logger).to receive(:warn).with(hash_including(message: "rate_limit_unknown_characteristic"))

      evaluator(rules: [rule]).evaluate
    end
@@ -138,7 +138,7 @@ RSpec.describe Labkit::RateLimit::Evaluator do
    it "returns :allow on Redis error and WARNs" do
      rule = make_rule
      allow(redis).to receive(:incr).and_raise(RuntimeError, "connection refused")
      expect(logger).to receive(:warn).with(a_string_including("rate_limit_redis_error"))
      expect(logger).to receive(:warn).with(hash_including(message: "rate_limit_redis_error"))

      result = evaluator(rules: [rule]).evaluate
      expect(result).to eq(:allow)
@@ -152,19 +152,17 @@ RSpec.describe Labkit::RateLimit::Evaluator do
      allow(redis).to receive(:expire)

      expect(logger).to receive(:info) do |msg|
        data = JSON.parse(msg)
        expect(data["severity"]).to eq("INFO")
        expect(data["message"]).to eq("rate_limit_check")
        expect(data["call_site"]).to eq("rack_request")
        expect(data["rule_index"]).to eq(0)
        expect(data["action"]).to eq("block")
        expect(data["limit"]).to eq(100)
        expect(data["period"]).to eq(60)
        expect(data["count"]).to eq(42)
        expect(data["matched"]).to be(true)
        expect(data).to have_key("exceeded")
        expect(data["identifier"]).to be_a(Hash)
        expect(data["redis_key"]).to eq("labkit:rl:rack_request:0:user:42")
        expect(msg[:message]).to eq("rate_limit_check")
        expect(msg[:call_site]).to eq("rack_request")
        expect(msg[:rule_index]).to eq(0)
        expect(msg[:action]).to eq("block")
        expect(msg[:limit]).to eq(100)
        expect(msg[:period]).to eq(60)
        expect(msg[:count]).to eq(42)
        expect(msg[:matched]).to be(true)
        expect(msg).to have_key(:exceeded)
        expect(msg[:identifier]).to be_a(Hash)
        expect(msg[:redis_key]).to eq("labkit:rl:rack_request:0:user:42")
      end

      evaluator(rules: [rule]).evaluate
+6 −7
Original line number Diff line number Diff line
@@ -151,8 +151,7 @@ RSpec.describe Labkit::RateLimit do
      )

      expect(result).to eq(:allow)
      expect(logger).to have_received(:warn).with(a_string_including("rate_limit_redis_error"))
      expect(logger).to have_received(:warn).with(a_string_including("allow"))
      expect(logger).to have_received(:warn).with(hash_including(message: "rate_limit_redis_error", result: "allow"))
    end
  end

@@ -184,7 +183,7 @@ RSpec.describe Labkit::RateLimit do
        )
      end.not_to raise_error

      expect(logger).to have_received(:warn).with(a_string_including("rate_limit_unknown_characteristic"))
      expect(logger).to have_received(:warn).with(hash_including(message: "rate_limit_unknown_characteristic"))
      expect(real_redis.get("labkit:rl:rack_request:0:unknown_key:unknown_characteristic")).to eq(1)
    end
  end
@@ -216,15 +215,15 @@ RSpec.describe Labkit::RateLimit do
  describe "scenario 11: structured log fields" do
    it "logs all required fields for a matched rule" do
      log_entries = []
      allow(logger).to receive(:info) { |msg| log_entries << JSON.parse(msg) }
      allow(logger).to receive(:info) { |msg| log_entries << msg }

      rules = [rule(match: {}, limit: 100, characteristics: [:user])]
      check(rules: rules)

      expect(log_entries).not_to be_empty
      entry = log_entries.first
      expect(entry.keys).to include("call_site", "rule_index", "action", "limit", "period",
        "count", "matched", "exceeded", "identifier", "redis_key")
      expect(entry.keys).to include(:call_site, :rule_index, :action, :limit, :period,
        :count, :matched, :exceeded, :identifier, :redis_key)
    end
  end

@@ -256,7 +255,7 @@ RSpec.describe Labkit::RateLimit do
        )
      end.not_to raise_error

      expect(logger).to have_received(:warn).with(a_string_including("rate_limit_invalid_call_site"))
      expect(logger).to have_received(:warn).with(hash_including(message: "rate_limit_invalid_call_site"))
      expect(real_redis.get("labkit:rl:bad_site:0:user:42")).to eq(1)
    end
  end