feat: add logging hook (spec Appendix A) (#229)

Signed-off-by: Jose Colella <jose.colella@gusto.com>
Co-authored-by: Claude Opus 4.6 (1M context) <noreply@anthropic.com>

Author: josecolella

lib/open_feature/sdk/hooks.rb

@@ -4,3 +4,4 @@
 require_relative "hooks/hook"
 require_relative "hooks/hook_context"
 require_relative "hooks/hook_executor"
+require_relative "hooks/logging_hook"

lib/open_feature/sdk/hooks/logging_hook.rb

@@ -0,0 +1,84 @@
+# frozen_string_literal: true
+
+module OpenFeature
+  module SDK
+    module Hooks
+      class LoggingHook
+        include Hook
+
+        def initialize(logger: nil, include_evaluation_context: false)
+          @logger = logger
+          @include_evaluation_context = include_evaluation_context
+        end
+
+        def before(hook_context:, hints:)
+          logger&.debug { build_before_message(hook_context) }
+          nil
+        end
+
+        def after(hook_context:, evaluation_details:, hints:)
+          logger&.debug { build_after_message(hook_context, evaluation_details) }
+          nil
+        end
+
+        def error(hook_context:, exception:, hints:)
+          logger&.error { build_error_message(hook_context, exception) }
+          nil
+        end
+
+        private
+
+        def logger
+          @logger || OpenFeature::SDK.configuration.logger
+        end
+
+        def build_before_message(hook_context)
+          parts = base_parts("before", hook_context)
+          parts << "evaluation_context=#{format_context(hook_context.evaluation_context)}" if @include_evaluation_context
+          parts.join(" ")
+        end
+
+        def build_after_message(hook_context, evaluation_details)
+          parts = base_parts("after", hook_context)
+          parts << "reason=#{sanitize(evaluation_details.reason)}" if evaluation_details.reason
+          parts << "variant=#{sanitize(evaluation_details.variant)}" if evaluation_details.variant
+          parts << "value=#{sanitize(evaluation_details.value)}"
+          parts << "evaluation_context=#{format_context(hook_context.evaluation_context)}" if @include_evaluation_context
+          parts.join(" ")
+        end
+
+        def build_error_message(hook_context, exception)
+          parts = base_parts("error", hook_context)
+          error_code = exception.respond_to?(:error_code) ? exception.error_code : Provider::ErrorCode::GENERAL
+          parts << "error_code=#{sanitize(error_code)}"
+          parts << "error_message=#{sanitize(exception.message)}"
+          parts << "evaluation_context=#{format_context(hook_context.evaluation_context)}" if @include_evaluation_context
+          parts.join(" ")
+        end
+
+        def base_parts(stage, hook_context)
+          domain = hook_context.client_metadata&.domain
+          provider_name = hook_context.provider_metadata&.name
+          [
+            "stage=#{stage}",
+            "domain=#{sanitize(domain)}",
+            "provider_name=#{sanitize(provider_name)}",
+            "flag_key=#{sanitize(hook_context.flag_key)}",
+            "default_value=#{sanitize(hook_context.default_value)}"
+          ]
+        end
+
+        def format_context(evaluation_context)
+          return "" unless evaluation_context
+          fields = evaluation_context.fields.dup
+          fields["targeting_key"] = evaluation_context.targeting_key if evaluation_context.targeting_key
+          fields.map { |k, v| "#{sanitize(k)}=#{sanitize(v)}" }.join(", ")
+        end
+
+        def sanitize(value)
+          value.to_s.gsub(/[\n\r]/, " ")
+        end
+      end
+    end
+  end
+end

spec/open_feature/sdk/hooks/logging_hook_spec.rb

@@ -0,0 +1,248 @@
+# frozen_string_literal: true
+
+require "spec_helper"
+
+RSpec.describe OpenFeature::SDK::Hooks::LoggingHook do
+  let(:client_metadata) { OpenFeature::SDK::ClientMetadata.new(domain: "test-domain") }
+  let(:provider_metadata) { OpenFeature::SDK::Provider::ProviderMetadata.new(name: "test-provider") }
+  let(:evaluation_context) { OpenFeature::SDK::EvaluationContext.new(targeting_key: "user-123", env: "prod") }
+
+  let(:hook_context) do
+    OpenFeature::SDK::Hooks::HookContext.new(
+      flag_key: "my-flag",
+      flag_value_type: :boolean,
+      default_value: false,
+      evaluation_context: evaluation_context,
+      client_metadata: client_metadata,
+      provider_metadata: provider_metadata
+    )
+  end
+
+  let(:evaluation_details) do
+    resolution = OpenFeature::SDK::Provider::ResolutionDetails.new(
+      value: true,
+      reason: "TARGETING_MATCH",
+      variant: "enabled"
+    )
+    OpenFeature::SDK::EvaluationDetails.new(
+      flag_key: "my-flag",
+      resolution_details: resolution
+    )
+  end
+
+  let(:logger) { double("logger") }
+  let(:hints) { OpenFeature::SDK::Hooks::Hints.new }
+
+  describe "#before" do
+    it "logs at debug level with correct fields" do
+      hook = described_class.new(logger: logger)
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).to include("stage=before")
+        expect(message).to include("domain=test-domain")
+        expect(message).to include("provider_name=test-provider")
+        expect(message).to include("flag_key=my-flag")
+        expect(message).to include("default_value=false")
+      end
+
+      hook.before(hook_context: hook_context, hints: hints)
+    end
+
+    it "does not include evaluation_context by default" do
+      hook = described_class.new(logger: logger)
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).not_to include("evaluation_context=")
+      end
+
+      hook.before(hook_context: hook_context, hints: hints)
+    end
+
+    it "includes evaluation_context when enabled" do
+      hook = described_class.new(logger: logger, include_evaluation_context: true)
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).to include("evaluation_context=")
+        expect(message).to include("targeting_key=user-123")
+        expect(message).to include("env=prod")
+      end
+
+      hook.before(hook_context: hook_context, hints: hints)
+    end
+
+    it "returns nil" do
+      hook = described_class.new(logger: logger)
+      allow(logger).to receive(:debug)
+      expect(hook.before(hook_context: hook_context, hints: hints)).to be_nil
+    end
+  end
+
+  describe "#after" do
+    it "logs at debug level with evaluation details" do
+      hook = described_class.new(logger: logger)
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).to include("stage=after")
+        expect(message).to include("domain=test-domain")
+        expect(message).to include("provider_name=test-provider")
+        expect(message).to include("flag_key=my-flag")
+        expect(message).to include("default_value=false")
+        expect(message).to include("reason=TARGETING_MATCH")
+        expect(message).to include("variant=enabled")
+        expect(message).to include("value=true")
+      end
+
+      hook.after(hook_context: hook_context, evaluation_details: evaluation_details, hints: hints)
+    end
+
+    it "omits reason and variant when nil" do
+      resolution = OpenFeature::SDK::Provider::ResolutionDetails.new(value: "hello")
+      details = OpenFeature::SDK::EvaluationDetails.new(flag_key: "my-flag", resolution_details: resolution)
+      hook = described_class.new(logger: logger)
+
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).not_to include("reason=")
+        expect(message).not_to include("variant=")
+        expect(message).to include("value=hello")
+      end
+
+      hook.after(hook_context: hook_context, evaluation_details: details, hints: hints)
+    end
+
+    it "includes evaluation_context when enabled" do
+      hook = described_class.new(logger: logger, include_evaluation_context: true)
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).to include("evaluation_context=")
+        expect(message).to include("targeting_key=user-123")
+      end
+
+      hook.after(hook_context: hook_context, evaluation_details: evaluation_details, hints: hints)
+    end
+
+    it "returns nil" do
+      hook = described_class.new(logger: logger)
+      allow(logger).to receive(:debug)
+      expect(hook.after(hook_context: hook_context, evaluation_details: evaluation_details, hints: hints)).to be_nil
+    end
+  end
+
+  describe "#error" do
+    let(:exception) { StandardError.new("something went wrong") }
+
+    it "logs at error level with error fields" do
+      hook = described_class.new(logger: logger)
+      expect(logger).to receive(:error) do |&block|
+        message = block.call
+        expect(message).to include("stage=error")
+        expect(message).to include("domain=test-domain")
+        expect(message).to include("provider_name=test-provider")
+        expect(message).to include("flag_key=my-flag")
+        expect(message).to include("default_value=false")
+        expect(message).to include("error_code=GENERAL")
+        expect(message).to include("error_message=something went wrong")
+      end
+
+      hook.error(hook_context: hook_context, exception: exception, hints: hints)
+    end
+
+    it "uses error_code from exception when available" do
+      error_with_code = OpenFeature::SDK::ProviderInitializationError.new("init failed")
+      hook = described_class.new(logger: logger)
+
+      expect(logger).to receive(:error) do |&block|
+        message = block.call
+        expect(message).to include("error_code=PROVIDER_FATAL")
+      end
+
+      hook.error(hook_context: hook_context, exception: error_with_code, hints: hints)
+    end
+
+    it "includes evaluation_context when enabled" do
+      hook = described_class.new(logger: logger, include_evaluation_context: true)
+      expect(logger).to receive(:error) do |&block|
+        message = block.call
+        expect(message).to include("evaluation_context=")
+        expect(message).to include("targeting_key=user-123")
+      end
+
+      hook.error(hook_context: hook_context, exception: exception, hints: hints)
+    end
+
+    it "returns nil" do
+      hook = described_class.new(logger: logger)
+      allow(logger).to receive(:error)
+      expect(hook.error(hook_context: hook_context, exception: exception, hints: hints)).to be_nil
+    end
+  end
+
+  describe "#finally" do
+    it "does not log (uses default no-op from Hook module)" do
+      hook = described_class.new(logger: logger)
+      expect(logger).not_to receive(:debug)
+      expect(logger).not_to receive(:info)
+      expect(logger).not_to receive(:error)
+
+      hook.finally(hook_context: hook_context, evaluation_details: evaluation_details, hints: hints)
+    end
+  end
+
+  describe "logger fallback" do
+    it "falls back to OpenFeature::SDK.configuration.logger" do
+      config_logger = double("config_logger")
+      allow(OpenFeature::SDK).to receive(:configuration).and_return(
+        instance_double(OpenFeature::SDK::Configuration, logger: config_logger)
+      )
+
+      hook = described_class.new
+      expect(config_logger).to receive(:debug)
+
+      hook.before(hook_context: hook_context, hints: hints)
+    end
+
+    it "handles nil logger gracefully" do
+      allow(OpenFeature::SDK).to receive(:configuration).and_return(
+        instance_double(OpenFeature::SDK::Configuration, logger: nil)
+      )
+
+      hook = described_class.new
+      expect { hook.before(hook_context: hook_context, hints: hints) }.not_to raise_error
+    end
+  end
+
+  describe "log injection sanitization" do
+    it "sanitizes newlines in logged values" do
+      injected_context = OpenFeature::SDK::Hooks::HookContext.new(
+        flag_key: "safe-key\ninjected=malicious",
+        flag_value_type: :boolean,
+        default_value: false,
+        evaluation_context: evaluation_context,
+        client_metadata: client_metadata,
+        provider_metadata: provider_metadata
+      )
+
+      hook = described_class.new(logger: logger)
+      expect(logger).to receive(:debug) do |&block|
+        message = block.call
+        expect(message).not_to include("\n")
+        expect(message).to include("safe-key injected=malicious")
+      end
+
+      hook.before(hook_context: injected_context, hints: hints)
+    end
+
+    it "sanitizes newlines in error messages" do
+      exception = StandardError.new("error\nfake_entry=injected")
+      hook = described_class.new(logger: logger)
+
+      expect(logger).to receive(:error) do |&block|
+        message = block.call
+        expect(message).not_to include("\n")
+        expect(message).to include("error fake_entry=injected")
+      end
+
+      hook.error(hook_context: hook_context, exception: exception, hints: hints)
+    end
+  end
+end