From 480e46b4186a4c959af98fe055cf0c19b0de3526 Mon Sep 17 00:00:00 2001 From: Stephen Hosom Date: Mon, 31 Aug 2026 10:28:37 -0400 Subject: [PATCH 1/3] Add provider timing metrics Emit structured, monotonic timing records around initialization, provider reads, calculations, writes, and audit operations so deployment latency can be attributed by phase and provider. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: d92ba3d2-77c4-461f-8d6f-25c3228476d1 --- lib/entitlements.rb | 72 +++++++++++++++++++++++++-------- spec/unit/entitlements_spec.rb | 74 +++++++++++++++++++++++++++++++++- 2 files changed, 128 insertions(+), 18 deletions(-) diff --git a/lib/entitlements.rb b/lib/entitlements.rb index 6e89811..8efcb3e 100644 --- a/lib/entitlements.rb +++ b/lib/entitlements.rb @@ -17,6 +17,7 @@ require "contracts" require "erb" +require "json" require "logger" require "ostruct" require "stringio" @@ -354,6 +355,29 @@ def self.set_logger(logger) end # :nocov: + def self.timed_operation(phase:, provider: nil, target: nil) + started_at = Process.clock_gettime(Process::CLOCK_MONOTONIC) + status = "error" + result = yield + status = "success" + result + ensure + duration = Process.clock_gettime(Process::CLOCK_MONOTONIC) - started_at + fields = { + metric: "entitlements.operation.duration_seconds", + value: duration.round(6), + phase: phase, + status: status + } + fields[:provider] = provider if provider + fields[:target] = target if target + begin + logger.info("METRIC #{JSON.generate(fields)}") + rescue StandardError => e + warn "Failed to log timing metric: #{e.class}: #{e.message}" + end + end + # Calculate - This runs the entitlements logic to calculate the differences, ultimately # populating a cache and returning a list of actions. The cache and actions can then be # consumed by `execute` to implement the changes. @@ -364,13 +388,17 @@ def self.set_logger(logger) Contract C::None => C::ArrayOf[Entitlements::Models::Action] def self.calculate # Load extras that are configured. - Entitlements.load_extras if Entitlements.config.key?("extras") + if Entitlements.config.key?("extras") + timed_operation(phase: "load_extras") { Entitlements.load_extras } + end # Pre-fetch people from configured people data sources. - Entitlements.prefetch_people + timed_operation(phase: "prefetch_people") { Entitlements.prefetch_people } # Register filters that are configured. - Entitlements.register_filters if Entitlements.config.key?("filters") + if Entitlements.config.key?("filters") + timed_operation(phase: "register_filters") { Entitlements.register_filters } + end # Keep track of the total change count. cache[:change_count] = 0 @@ -385,8 +413,9 @@ def self.calculate Concurrent::Future.execute({ executor: thread_pool }) do group_start = Time.now logger.debug("Begin prefetch and validate for #{group_name}") - obj.prefetch - obj.validate + provider = Entitlements.config["groups"].fetch(group_name).fetch("type") + timed_operation(phase: "prefetch", provider:, target: group_name) { obj.prefetch } + timed_operation(phase: "validate", provider:, target: group_name) { obj.validate } logger.debug("Finished prefetch and validate for #{group_name} in #{Time.now - group_start}") end end @@ -398,7 +427,8 @@ def self.calculate calc_start = Time.now actions = [] Entitlements.child_classes.map do |group_name, obj| - obj.calculate + provider = Entitlements.config["groups"].fetch(group_name).fetch("type") + timed_operation(phase: "calculate", provider:, target: group_name) { obj.calculate } if obj.change_count > 0 logger.debug "Group #{group_name.inspect} contributes #{obj.change_count} change(s)." cache[:change_count] += obj.change_count @@ -423,7 +453,9 @@ def self.calculate ] => nil def self.execute(actions:) # Set up auditors. - Entitlements.auditors.each { |auditor| auditor.setup } + Entitlements.auditors.each do |auditor| + timed_operation(phase: "audit_setup", provider: auditor.provider_id) { auditor.setup } + end # Track any raised exception to pass to the auditors. provider_exception = nil @@ -433,14 +465,18 @@ def self.execute(actions:) # Sort the child classes by priority begin # Pre-apply changes for each class. - Entitlements.child_classes.each do |_, obj| - obj.preapply + Entitlements.child_classes.each do |group_name, obj| + provider = Entitlements.config["groups"].fetch(group_name).fetch("type") + timed_operation(phase: "preapply", provider:, target: group_name) { obj.preapply } end # Apply changes from all actions. actions.each do |action| obj = Entitlements.child_classes.fetch(action.ou) - obj.apply(action) + provider = Entitlements.config["groups"].fetch(action.ou).fetch("type") + timed_operation(phase: "apply", provider:, target: action.ou) do + obj.apply(action) + end successful_actions.add(action.dn) end rescue => e @@ -457,11 +493,13 @@ def self.execute(actions:) logger.debug "Recording data to #{Entitlements.auditors.size} audit provider(s)" Entitlements.auditors.each do |audit| begin - audit.commit( - actions: actions, - successful_actions: successful_actions, - provider_exception: provider_exception - ) + timed_operation(phase: "audit_commit", provider: audit.provider_id) do + audit.commit( + actions: actions, + successful_actions: successful_actions, + provider_exception: provider_exception + ) + end logger.debug "Audit #{audit.description} completed successfully" rescue => e logger.error "Audit #{audit.description} failed: #{e.class} #{e.message}" @@ -564,7 +602,9 @@ def self.prefetch_people objects = people_data_sources.map do |ds_name, ds_config| people_obj = Entitlements::Data::People.new_from_config(ds_config) - people_obj.read + timed_operation(phase: "prefetch_people_source", provider: ds_config.fetch("type"), target: ds_name) do + people_obj.read + end [ds_name, people_obj] end.to_h diff --git a/spec/unit/entitlements_spec.rb b/spec/unit/entitlements_spec.rb index 96c05c9..6b47e73 100644 --- a/spec/unit/entitlements_spec.rb +++ b/spec/unit/entitlements_spec.rb @@ -171,8 +171,78 @@ end end + describe "#timed_operation" do + let(:log_output) { StringIO.new } + let(:timing_logger) { Logger.new(log_output) } + + before do + described_class.set_logger(timing_logger) + end + + it "logs a successful operation with provider details" do + allow(Process).to receive(:clock_gettime) + .with(Process::CLOCK_MONOTONIC) + .and_return(10.0, 12.3456789) + + result = described_class.timed_operation( + phase: "apply", + provider: "aad", + target: "apps/azure_aad" + ) { :result } + + expect(result).to eq(:result) + metric = JSON.parse(log_output.string.sub(/\A.*METRIC /, "")) + expect(metric).to eq( + "metric" => "entitlements.operation.duration_seconds", + "value" => 2.345679, + "phase" => "apply", + "status" => "success", + "provider" => "aad", + "target" => "apps/azure_aad" + ) + end + + it "logs failed operations before propagating the exception" do + allow(Process).to receive(:clock_gettime) + .with(Process::CLOCK_MONOTONIC) + .and_return(20.0, 20.25) + + expect do + described_class.timed_operation(phase: "audit_setup") { raise "Boom" } + end.to raise_error(RuntimeError, "Boom") + + metric = JSON.parse(log_output.string.sub(/\A.*METRIC /, "")) + expect(metric).to eq( + "metric" => "entitlements.operation.duration_seconds", + "value" => 0.25, + "phase" => "audit_setup", + "status" => "error" + ) + end + + it "does not allow metric failures to change operation behavior" do + allow(Process).to receive(:clock_gettime) + .with(Process::CLOCK_MONOTONIC) + .and_return(30.0, 30.5) + allow(timing_logger).to receive(:info).and_raise(IOError, "logger unavailable") + expect(described_class).to receive(:warn).with("Failed to log timing metric: IOError: logger unavailable") + + expect(described_class.timed_operation(phase: "apply") { :result }).to eq(:result) + end + end + describe "#calculate" do let(:cache) { { people_obj: people_ldap } } + let(:entitlements_config_hash) do + { + "extras" => {}, + "filters" => {}, + "groups" => { + "ldap-dir" => { "type" => "ldap" }, + "other-ldap-dir" => { "type" => "ldap" } + } + } + end let(:action1) { instance_double(Entitlements::Models::Action) } let(:action2) { instance_double(Entitlements::Models::Action) } let(:actions) { [action1, action2] } @@ -208,8 +278,8 @@ let(:cache) { { people_obj: people_ldap } } let(:people_ldap) { instance_double(Entitlements::Data::People::LDAP) } - let(:auditor1) { instance_double(Entitlements::Auditor::Base) } - let(:auditor2) { instance_double(Entitlements::Auditor::Base) } + let(:auditor1) { instance_double(Entitlements::Auditor::Base, provider_id: "auditor1") } + let(:auditor2) { instance_double(Entitlements::Auditor::Base, provider_id: "auditor2") } let(:action1) { instance_double(Entitlements::Models::Action) } let(:action2) { instance_double(Entitlements::Models::Action) } From a7dc84d01e41cf298e13a7a70b8d42c4866382cf Mon Sep 17 00:00:00 2001 From: Stephen Hosom Date: Mon, 31 Aug 2026 10:32:38 -0400 Subject: [PATCH 2/3] Make timing metrics aggregatable Add run correlation, parent and concurrent span semantics, operation counts, and metric documentation so provider service time cannot be confused with deployment wall time. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: d92ba3d2-77c4-461f-8d6f-25c3228476d1 --- docs/metrics.md | 26 ++++++++++++++++++++++++++ lib/entitlements.rb | 32 +++++++++++++++++++++++++------- spec/unit/entitlements_spec.rb | 9 ++++++++- 3 files changed, 59 insertions(+), 8 deletions(-) create mode 100644 docs/metrics.md diff --git a/docs/metrics.md b/docs/metrics.md new file mode 100644 index 0000000..73f7e81 --- /dev/null +++ b/docs/metrics.md @@ -0,0 +1,26 @@ +# Timing metrics + +Entitlements emits timing records through its logger for deployment analysis. Each record begins with `METRIC` followed by a JSON object: + +```text +METRIC {"metric":"entitlements.operation.duration_seconds","value":11.204,"phase":"apply","status":"success","run_id":"fc85bb97-48f4-4f88-bb90-63e52cb01e9f","span":"leaf","concurrent":false,"provider":"aad","target":"apps/azure_aad","count":1} +``` + +The fields are: + +| Field | Description | +| --- | --- | +| `metric` | Metric name. Currently always `entitlements.operation.duration_seconds`. | +| `value` | Elapsed monotonic time in seconds. | +| `phase` | Operation being measured. | +| `status` | `success` or `error`. | +| `run_id` | Identifier shared by records from one process. Set `ENTITLEMENTS_RUN_ID` to correlate with an external deployment identifier. | +| `span` | `parent` for top-level wall-clock spans and `leaf` for individual operations. | +| `concurrent` | Whether the operation may overlap other records from the same phase. | +| `provider` | Backend type or audit provider identifier, when applicable. | +| `target` | Configured group or data-source name, when applicable. | +| `count` | Number of operations represented by the record, when applicable. | + +`calculate_total` and `execute_total` are parent spans and report wall-clock time. Leaf spans identify initialization, reads, calculations, writes, and audit operations. Prefetch and validation run concurrently, so their durations describe provider service time and must not be summed to calculate wall-clock duration. + +Raw action identifiers are not included because an action can identify an individual user and would create an unbounded metric field. diff --git a/lib/entitlements.rb b/lib/entitlements.rb index 8efcb3e..ba51092 100644 --- a/lib/entitlements.rb +++ b/lib/entitlements.rb @@ -20,6 +20,7 @@ require "json" require "logger" require "ostruct" +require "securerandom" require "stringio" require "uri" require "yaml" @@ -90,6 +91,7 @@ def self.reset! @config_file = nil @config_path_override = nil @person_extra_methods = {} + @run_id = nil reset_extras! Entitlements::Data::Groups::Calculated.reset! @@ -355,7 +357,11 @@ def self.set_logger(logger) end # :nocov: - def self.timed_operation(phase:, provider: nil, target: nil) + def self.run_id + @run_id ||= ENV["ENTITLEMENTS_RUN_ID"] || SecureRandom.uuid + end + + def self.timed_operation(phase:, provider: nil, target: nil, span: "leaf", concurrent: false, count: nil) started_at = Process.clock_gettime(Process::CLOCK_MONOTONIC) status = "error" result = yield @@ -367,10 +373,14 @@ def self.timed_operation(phase:, provider: nil, target: nil) metric: "entitlements.operation.duration_seconds", value: duration.round(6), phase: phase, - status: status + status: status, + run_id: run_id, + span: span, + concurrent: concurrent } fields[:provider] = provider if provider fields[:target] = target if target + fields[:count] = count if count begin logger.info("METRIC #{JSON.generate(fields)}") rescue StandardError => e @@ -387,6 +397,10 @@ def self.timed_operation(phase:, provider: nil, target: nil) # Returns the array of actions. Contract C::None => C::ArrayOf[Entitlements::Models::Action] def self.calculate + timed_operation(phase: "calculate_total", span: "parent") { calculate_actions } + end + + def self.calculate_actions # Load extras that are configured. if Entitlements.config.key?("extras") timed_operation(phase: "load_extras") { Entitlements.load_extras } @@ -414,8 +428,8 @@ def self.calculate group_start = Time.now logger.debug("Begin prefetch and validate for #{group_name}") provider = Entitlements.config["groups"].fetch(group_name).fetch("type") - timed_operation(phase: "prefetch", provider:, target: group_name) { obj.prefetch } - timed_operation(phase: "validate", provider:, target: group_name) { obj.validate } + timed_operation(phase: "prefetch", provider: provider, target: group_name, concurrent: true) { obj.prefetch } + timed_operation(phase: "validate", provider: provider, target: group_name, concurrent: true) { obj.validate } logger.debug("Finished prefetch and validate for #{group_name} in #{Time.now - group_start}") end end @@ -428,7 +442,7 @@ def self.calculate actions = [] Entitlements.child_classes.map do |group_name, obj| provider = Entitlements.config["groups"].fetch(group_name).fetch("type") - timed_operation(phase: "calculate", provider:, target: group_name) { obj.calculate } + timed_operation(phase: "calculate", provider: provider, target: group_name) { obj.calculate } if obj.change_count > 0 logger.debug "Group #{group_name.inspect} contributes #{obj.change_count} change(s)." cache[:change_count] += obj.change_count @@ -452,6 +466,10 @@ def self.calculate actions: C::ArrayOf[Entitlements::Models::Action] ] => nil def self.execute(actions:) + timed_operation(phase: "execute_total", span: "parent") { execute_actions(actions: actions) } + end + + def self.execute_actions(actions:) # Set up auditors. Entitlements.auditors.each do |auditor| timed_operation(phase: "audit_setup", provider: auditor.provider_id) { auditor.setup } @@ -467,14 +485,14 @@ def self.execute(actions:) # Pre-apply changes for each class. Entitlements.child_classes.each do |group_name, obj| provider = Entitlements.config["groups"].fetch(group_name).fetch("type") - timed_operation(phase: "preapply", provider:, target: group_name) { obj.preapply } + timed_operation(phase: "preapply", provider: provider, target: group_name) { obj.preapply } end # Apply changes from all actions. actions.each do |action| obj = Entitlements.child_classes.fetch(action.ou) provider = Entitlements.config["groups"].fetch(action.ou).fetch("type") - timed_operation(phase: "apply", provider:, target: action.ou) do + timed_operation(phase: "apply", provider: provider, target: action.ou, count: 1) do obj.apply(action) end successful_actions.add(action.dn) diff --git a/spec/unit/entitlements_spec.rb b/spec/unit/entitlements_spec.rb index 6b47e73..e451b6a 100644 --- a/spec/unit/entitlements_spec.rb +++ b/spec/unit/entitlements_spec.rb @@ -177,6 +177,7 @@ before do described_class.set_logger(timing_logger) + allow(described_class).to receive(:run_id).and_return("run-123") end it "logs a successful operation with provider details" do @@ -197,6 +198,9 @@ "value" => 2.345679, "phase" => "apply", "status" => "success", + "run_id" => "run-123", + "span" => "leaf", + "concurrent" => false, "provider" => "aad", "target" => "apps/azure_aad" ) @@ -216,7 +220,10 @@ "metric" => "entitlements.operation.duration_seconds", "value" => 0.25, "phase" => "audit_setup", - "status" => "error" + "status" => "error", + "run_id" => "run-123", + "span" => "leaf", + "concurrent" => false ) end From 853eeaefd0d8a3fab83e84519397fbc08b757d13 Mon Sep 17 00:00:00 2001 From: Stephen Hosom Date: Mon, 31 Aug 2026 15:26:53 -0400 Subject: [PATCH 3/3] rework this to match closer to our real standard for metrics --- Gemfile.lock | 4 +- docs/metrics.md | 26 ------- entitlements-app.gemspec | 1 + lib/entitlements.rb | 67 +++++++++------- lib/entitlements/cli.rb | 2 + lib/version.rb | 2 +- spec/unit/entitlements_spec.rb | 108 +++++++++++++++----------- spec/unit/spec_helper.rb | 6 ++ vendor/cache/dogstatsd-ruby-5.7.1.gem | Bin 0 -> 24064 bytes 9 files changed, 115 insertions(+), 101 deletions(-) delete mode 100644 docs/metrics.md create mode 100644 vendor/cache/dogstatsd-ruby-5.7.1.gem diff --git a/Gemfile.lock b/Gemfile.lock index a9787f3..56afec2 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -1,8 +1,9 @@ PATH remote: . specs: - entitlements-app (1.2.1) + entitlements-app (1.2.2) concurrent-ruby (~> 1.3, >= 1.3.1) + dogstatsd-ruby (~> 5.7) faraday (~> 2.0) logger (~> 1.6) net-ldap (~> 0.19) @@ -39,6 +40,7 @@ GEM reline (>= 0.3.1) diff-lcs (1.5.1) docile (1.4.0) + dogstatsd-ruby (5.7.1) drb (2.2.1) faraday (2.14.1) faraday-net_http (>= 2.0, < 3.5) diff --git a/docs/metrics.md b/docs/metrics.md deleted file mode 100644 index 73f7e81..0000000 --- a/docs/metrics.md +++ /dev/null @@ -1,26 +0,0 @@ -# Timing metrics - -Entitlements emits timing records through its logger for deployment analysis. Each record begins with `METRIC` followed by a JSON object: - -```text -METRIC {"metric":"entitlements.operation.duration_seconds","value":11.204,"phase":"apply","status":"success","run_id":"fc85bb97-48f4-4f88-bb90-63e52cb01e9f","span":"leaf","concurrent":false,"provider":"aad","target":"apps/azure_aad","count":1} -``` - -The fields are: - -| Field | Description | -| --- | --- | -| `metric` | Metric name. Currently always `entitlements.operation.duration_seconds`. | -| `value` | Elapsed monotonic time in seconds. | -| `phase` | Operation being measured. | -| `status` | `success` or `error`. | -| `run_id` | Identifier shared by records from one process. Set `ENTITLEMENTS_RUN_ID` to correlate with an external deployment identifier. | -| `span` | `parent` for top-level wall-clock spans and `leaf` for individual operations. | -| `concurrent` | Whether the operation may overlap other records from the same phase. | -| `provider` | Backend type or audit provider identifier, when applicable. | -| `target` | Configured group or data-source name, when applicable. | -| `count` | Number of operations represented by the record, when applicable. | - -`calculate_total` and `execute_total` are parent spans and report wall-clock time. Leaf spans identify initialization, reads, calculations, writes, and audit operations. Prefetch and validation run concurrently, so their durations describe provider service time and must not be summed to calculate wall-clock duration. - -Raw action identifiers are not included because an action can identify an individual user and would create an unbounded metric field. diff --git a/entitlements-app.gemspec b/entitlements-app.gemspec index 717eda0..14549c1 100644 --- a/entitlements-app.gemspec +++ b/entitlements-app.gemspec @@ -17,6 +17,7 @@ Gem::Specification.new do |s| s.required_ruby_version = ">= 3.0.0" s.add_dependency "concurrent-ruby", "~> 1.3", ">= 1.3.1" + s.add_dependency "dogstatsd-ruby", "~> 5.7" s.add_dependency "faraday", "~> 2.0" s.add_dependency "net-ldap", "~> 0.19" s.add_dependency "octokit", "~> 4.18" diff --git a/lib/entitlements.rb b/lib/entitlements.rb index ba51092..c39fe0d 100644 --- a/lib/entitlements.rb +++ b/lib/entitlements.rb @@ -16,11 +16,11 @@ # :nocov: require "contracts" +require "datadog/statsd" require "erb" -require "json" require "logger" require "ostruct" -require "securerandom" +require "resolv" require "stringio" require "uri" require "yaml" @@ -91,7 +91,7 @@ def self.reset! @config_file = nil @config_path_override = nil @person_extra_methods = {} - @run_id = nil + @statsd = nil reset_extras! Entitlements::Data::Groups::Calculated.reset! @@ -357,34 +357,45 @@ def self.set_logger(logger) end # :nocov: - def self.run_id - @run_id ||= ENV["ENTITLEMENTS_RUN_ID"] || SecureRandom.uuid + def self.statsd + @statsd ||= build_statsd + end + + def self.set_statsd(statsd) + @statsd = statsd + end + + def self.close_statsd + @statsd&.close + @statsd = nil + end + + def self.build_statsd + host = Resolv.getaddress(ENV.fetch("DOGSTATSD_HOST", "localhost")) + port = Integer(ENV.fetch("DOGSTATSD_PORT", 28_125)) + tags = [ + "application:entitlements", + "kube_pod_name:#{ENV.fetch('KUBE_POD_NAME', 'not-on-kubernetes')}", + "app_env:#{ENV.fetch('APP_ENV', 'development')}" + ] + Datadog::Statsd.new(host, port, tags: tags) end def self.timed_operation(phase:, provider: nil, target: nil, span: "leaf", concurrent: false, count: nil) - started_at = Process.clock_gettime(Process::CLOCK_MONOTONIC) - status = "error" - result = yield - status = "success" - result - ensure - duration = Process.clock_gettime(Process::CLOCK_MONOTONIC) - started_at - fields = { - metric: "entitlements.operation.duration_seconds", - value: duration.round(6), - phase: phase, - status: status, - run_id: run_id, - span: span, - concurrent: concurrent - } - fields[:provider] = provider if provider - fields[:target] = target if target - fields[:count] = count if count - begin - logger.info("METRIC #{JSON.generate(fields)}") - rescue StandardError => e - warn "Failed to log timing metric: #{e.class}: #{e.message}" + tags = [ + "phase:#{phase}", + "status:error", + "span:#{span}", + "concurrent:#{concurrent}" + ] + tags << "provider:#{provider}" if provider + tags << "target:#{target}" if target + tags << "count:#{count}" if count + + statsd.time("entitlements.operation.duration", tags: tags) do + result = yield + tags[1] = "status:success" + result end end diff --git a/lib/entitlements/cli.rb b/lib/entitlements/cli.rb index 9f190f8..34ec45f 100644 --- a/lib/entitlements/cli.rb +++ b/lib/entitlements/cli.rb @@ -51,6 +51,8 @@ def self.run # Done. logger.info "Successfully applied #{Entitlements.cache[:change_count]} change(s)!" 0 + ensure + Entitlements.close_statsd end # :nocov: diff --git a/lib/version.rb b/lib/version.rb index 412c637..06191dc 100644 --- a/lib/version.rb +++ b/lib/version.rb @@ -2,6 +2,6 @@ module Entitlements module Version - VERSION = "1.2.1" + VERSION = "1.2.2" end end diff --git a/spec/unit/entitlements_spec.rb b/spec/unit/entitlements_spec.rb index e451b6a..99ea54a 100644 --- a/spec/unit/entitlements_spec.rb +++ b/spec/unit/entitlements_spec.rb @@ -171,71 +171,89 @@ end end - describe "#timed_operation" do - let(:log_output) { StringIO.new } - let(:timing_logger) { Logger.new(log_output) } + describe "#build_statsd" do + it "builds a DogStatsD client using the IAM defaults" do + allow(ENV).to receive(:fetch).and_call_original + allow(ENV).to receive(:fetch).with("DOGSTATSD_HOST", "localhost").and_return("dogstatsd.example.com") + allow(ENV).to receive(:fetch).with("DOGSTATSD_PORT", 28_125).and_return("28125") + allow(ENV).to receive(:fetch).with("KUBE_POD_NAME", "not-on-kubernetes").and_return("entitlements-123") + allow(ENV).to receive(:fetch).with("APP_ENV", "development").and_return("production") + allow(Resolv).to receive(:getaddress).with("dogstatsd.example.com").and_return("192.0.2.1") + + expect(Datadog::Statsd).to receive(:new).with( + "192.0.2.1", + 28_125, + tags: [ + "application:entitlements", + "kube_pod_name:entitlements-123", + "app_env:production" + ] + ).and_return(statsd) + + expect(described_class.build_statsd).to eq(statsd) + end + end - before do - described_class.set_logger(timing_logger) - allow(described_class).to receive(:run_id).and_return("run-123") + describe "#close_statsd" do + it "closes and clears the configured client" do + expect(statsd).to receive(:close).once + + described_class.close_statsd + described_class.close_statsd end + end - it "logs a successful operation with provider details" do - allow(Process).to receive(:clock_gettime) - .with(Process::CLOCK_MONOTONIC) - .and_return(10.0, 12.3456789) + describe "#timed_operation" do + it "measures a successful operation with provider details" do + tags = nil + expect(statsd).to receive(:time) do |metric, options, &block| + expect(metric).to eq("entitlements.operation.duration") + tags = options.fetch(:tags) + block.call + end result = described_class.timed_operation( phase: "apply", provider: "aad", - target: "apps/azure_aad" + target: "apps/azure_aad", + count: 1 ) { :result } expect(result).to eq(:result) - metric = JSON.parse(log_output.string.sub(/\A.*METRIC /, "")) - expect(metric).to eq( - "metric" => "entitlements.operation.duration_seconds", - "value" => 2.345679, - "phase" => "apply", - "status" => "success", - "run_id" => "run-123", - "span" => "leaf", - "concurrent" => false, - "provider" => "aad", - "target" => "apps/azure_aad" + expect(tags).to eq( + [ + "phase:apply", + "status:success", + "span:leaf", + "concurrent:false", + "provider:aad", + "target:apps/azure_aad", + "count:1" + ] ) end - it "logs failed operations before propagating the exception" do - allow(Process).to receive(:clock_gettime) - .with(Process::CLOCK_MONOTONIC) - .and_return(20.0, 20.25) + it "measures failed operations before propagating the exception" do + tags = nil + expect(statsd).to receive(:time) do |metric, options, &block| + expect(metric).to eq("entitlements.operation.duration") + tags = options.fetch(:tags) + block.call + end expect do described_class.timed_operation(phase: "audit_setup") { raise "Boom" } end.to raise_error(RuntimeError, "Boom") - metric = JSON.parse(log_output.string.sub(/\A.*METRIC /, "")) - expect(metric).to eq( - "metric" => "entitlements.operation.duration_seconds", - "value" => 0.25, - "phase" => "audit_setup", - "status" => "error", - "run_id" => "run-123", - "span" => "leaf", - "concurrent" => false + expect(tags).to eq( + [ + "phase:audit_setup", + "status:error", + "span:leaf", + "concurrent:false" + ] ) end - - it "does not allow metric failures to change operation behavior" do - allow(Process).to receive(:clock_gettime) - .with(Process::CLOCK_MONOTONIC) - .and_return(30.0, 30.5) - allow(timing_logger).to receive(:info).and_raise(IOError, "logger unavailable") - expect(described_class).to receive(:warn).with("Failed to log timing metric: IOError: logger unavailable") - - expect(described_class.timed_operation(phase: "apply") { :result }).to eq(:result) - end end describe "#calculate" do diff --git a/spec/unit/spec_helper.rb b/spec/unit/spec_helper.rb index 0f03937..5c909ef 100644 --- a/spec/unit/spec_helper.rb +++ b/spec/unit/spec_helper.rb @@ -134,6 +134,11 @@ module MyLetDeclarations let(:entitlements_config_file) { fixture("config.yaml") } let(:entitlements_config_hash) { nil } let(:logger) { Entitlements.dummy_logger } + let(:statsd) do + instance_double(Datadog::Statsd).tap do |client| + allow(client).to receive(:time) { |*, &block| block.call } + end + end end module Contracts @@ -163,6 +168,7 @@ def instance_double(klass, *args) Entitlements.validate_configuration_file! end Entitlements.set_logger(logger) + Entitlements.set_statsd(statsd) end config.after :each do diff --git a/vendor/cache/dogstatsd-ruby-5.7.1.gem b/vendor/cache/dogstatsd-ruby-5.7.1.gem new file mode 100644 index 0000000000000000000000000000000000000000..f377a79764f2187a83061786e590ad92cfee2334 GIT binary patch literal 24064 zcmeFXQ;;uA5IwfGy?fWTZQHhO+qP}*-nEUpwr%hJ*0%B`c}VJ?O64V~3C7lLlD84rMM5Gq;hrUX##~Rke}LYPxyW}F z)aZ3XE=vEszP;i9qZp?z?PIl6w;xhjyPi2mKGDp zS9jJ231(h2NDJ0>*<|y!nGzNAMAH zJRdkK1Pfiq0ZLJ0>nq`!kx#_dkZf(n3+#QKLdFi%`IbFt$`#XKaKPL>0OE zSd-r!@)r`%-H)XucVin$eLQer2an)7PJT|JvEZZOb>Ze`f>NE!3k7LG+kAr8e{l+V z>uTX$6suMV)wBsDG^$t^N@Rw7`_vGV7>#pG#!yQKO~!C^QrS8^Bp^5w7G;BMO8r6m z=Tw2SGep`jmb>Y)Q!S4oER@?|?}`h;gbHX0d-#Oq@Zk7EJwJm6TS{;BpRZX^M6+g9 zTm%l9Cy!2SqIHyC4u@^nvYksijIDmqptl(sYi21`ZI6R)HfhQOU zTD20&^@og?^HbdZsApuNvD4IM^1%*9hM|_t364GLxh^b%pW*!?*>bt=nuvN1Ew+al z+Xl}zA0HN803Q@tuyGMa?V#>0Y2U2}bJp+xE>Yuhn3S~QP0?kay2^#Djfk-Egic0Y zJCKWeDbp;=U#HHxjUM^Zr@1@y0W1mdysUI**cLnKDVJ$hZOsyZCr`ezilV_l$SSI7 z+xD!!iXE>j&w`7GmZ zG~}xk*xz4)q?rNo&a-Ns#sEN%P@h9oO4%rjMFyixRQD&rF-E7HZZ+Cue}{(8zt~G3 zt4NG7rgvCT0lt?rsQ<67+W-6V`d_&JKL-4NkN;WOIoR3$5B$%>^8fSy|9!Lke;(<7 z=4QZ#>;FyA<2lm)_zbn_txEaiK} zPHv9QuLgm@8BNMp%~Wrw|xAT2bE zu|88+0UX1G2q4JtqPN=#5kexRNp}<)#yG>!tdX36N1}Ghy_oDMr2o z^S_ZHq+tsru@I^kapr!wA=LO`M~W|jGgcqaAbDhrptu$yu_gYT|9&A@YtOH2(a6u@ zqyhtvJ|5?K|17CP#p#0OwVWXOCdi7ZK9w1UT0_5CF$!n zF+(LG?LOVLdW}sx;d?aj_mBE#Cj&Y0fjAOdpLqtu11^odzcFuC4gu{-R^QKel`Hl! zAta5jA9pMIHtj?&FCO~68#`M8MEOG9-y!jyt*_qopn^P*AUvssFWU1rUMFssmS<#N z+x~5@*7c7vBD{N-S0vMCK(0Et_5^M(?z=sk{3sC)@d${UbO8VMrhtb2_TMikZ>wJW zYY$!kdKXG<`<+OOfqlQXn4VpK&;r52n>zwR0N19^eG`d3e$S@ez?entWOeVgMZNYm zx~%ot%FFI$`1+22?{~3SEdtPF(m!iwSAl-p1qy(}pC5;cW{(B~;M^B3=tt!SR1iIm>>Todoz;_JG*`mO*>m# z^%v@ZuFqGAACKkDUB8`&(eJtSG2ici-+_-&5{X|2{!LHcir@a>el1DodVaY-xZBHl>tmd*Rn%4B@G}{{^U_0&hVO z#0LMi3oDN$;qM@##Lot$AfHPOPq7lz7lEadGLOQN)uOIWcTdmLu>?adTyZNA<>ST% zjyss$+LcyK+&3xwAsbgL8^}(5h&}hu>DvY^?z0u3ne;O7z^m6%7h;JbgjlOP_Rs@# zzI#F&#y#AF4Zk+;{o81t40Gt?8mLBt+ODBGUMZs2vX|Qv7|vUnC13@5#?VbJT<9{|RP3=mq(3Z9Mq*gUQf(ef7*g=%K4#} z%_}{SsHx}rLDg{6Nb8vbZ4vj*--3J&F*o?%?sRdRFE9A(#|t`n^l^xG&<0aMUP5EE zYtv%l?52gNVMIzMu+(*>yT20|$duzMT_W^{wZd~)nPl%x!2iyMQ(8QKJd9iX9g$;+ zx3Nrj>iN#azV~;bu>4>pnkGGaGMGRGdpVv>2uc}SOx<xYP%5U$`Mn6BvQ@jY*o z-0AVXZ)wu_$SF4i;{snkH5ybk*9LG}2l+yz{7r&!=hYQ}l#+x6JK%+f*MD`;G&Grs z{=Nibc?5!i4D+i4Poj*SbGgToHLSsiQ?#mmpWyrb1(mp!8)g;f+5mNe$SHT)KT1Dm z9@LvQjqJ{YSGbbMxZ6^oW&lP)uyqTDc7t0PgU4C#3=l%SAezYI z&TZhvnn`}tc4j+g6T_Jc{`fnRtm%j^kzyIn2UN)zZFI{R6a|d;8c3E5aoe^3YuFC{ zi1^Xr^@5GZiMubC&u?pN1ocA;P9A18W+sqf!!Y%tn$2Ur@m6wENPlO5d?2qO8uYuNNOXUK|3je*srojW-n zh?`6r{c0Qvg@ZeyLnYat6(VG)n3{#*GH%VoL205G}6A~d*DhFOnn+SfoU-LVC!*5GK5dMKGK3AGQ-}!>M5E10 zIPwx%qRYFqQuLE1mXdQ$DwE-fva)|s70A|7CX$7Q?h8ZEgmB;_Q355QetU?8rlv59 zT6*D7G5#rkyx$gTo8qYFmkoBFJN;Qb*L!;%#2d%Lc;64VH$yb?wcG7%+Hv}&XZDwTO~*yWU|sc%+tEth57P%1uMOe5%dgR?96 zG9F_=D`MoM3QZaos!=!MSImf28KiqcG}ks@moq#Fg0ny&s=!DoNDhUNLw=c6YAv*z z?83d2!D*6Qs_ubXulI=`l~$!)o=6YnhT1_IY$sF`Sdiv;8iAUxf2&gU#T!0AB42=1 zN%g?HJF3{g&J4T*2h-}~4cd^AleYg({n}zort%+no(g?imdKY{FN_-9>?jin^*3Ov z9#no4IpjCy4Upu4VUN`igY!lD%nKr7d{VmN~!{Udmk4-S<;R@g*${3^s6vKxPo zdwh(glUJw-FB@59%?$5-KnTVtQfPpp7kC0zTE|Qz@8QwSvnA2(^SK3p;;#iui9w>3 z+NLj516rx@CkFqtS^<=JQv*Fz){{p$FnLtH>Epe};D72QcNlq-6uK6&^pnp)WjvDqa|a24`*1*eoxL|5jS$K|e3H*O zJGlEovpoUkA|%HI>kv)^50XV;PNg_><-uQMuRY`M zhaeW6?RlzKv_U4j>WM7bK$~zT)(=bB@ClRVZ4JKg>9(c{d8M)!0m4Pzrn0UOa;7%q zWx|gKQfbr&Rh$2VvaBM7IjuMz6=mBKUb~iT$f|kN6&f4;?gyuue%SVu+NM=lF{Yx- z8fZ#Z{LCma3~bARmD#awn>q_B2;nq+6%S(QTC}RiE)HAan(4{O&R+t`ry9JOon}YF zYQ6stsW*Zij;{sAWk0P)XQ}{%20K}Q3Hk~GbU$k#ESbmbH^1>zpM5Dd`=nx|Y}@o~Qs=ZID`?T{2Dq=tF9l13Snky{ob zX%whAlk^cwl2h@I!D6IrTp+9KTAx%QdlZq}wk52Y4ZRMV;~JL~DnEh)y<)#8TUG^mVwTdlb@^+o6juS7f zbn9;=WC$o##T~H9>KVSB)pJOTa2;qazKcR}?d!&jf-}nGZWEW=Nrrt}2uFETiL@c( z;#Da(m7PlR2AT)sW)|sUwUyy)Ff_OV1?O-f0VNFq8^FWxOUBUnY=6dIBDgbbpc`Ld z8Mi^-Jb|HYugB7_4L{D@%T9-kO!E^`St1!3&8>=6_e$j<7Y^6-WuNkBvt28%7E=+ z3eS;b9)h*PLk2Hr(qOw-)qaX8gAH=;qO>Wp=z@IFeTO2<6imMol*_Hn5H|PXB%;k^ z>1}9)!=!e07@N0vQZ11Hv|3$qUVVAZW{MEqm05TSLFR2vG!eSLg} zxv>)?@_ zqamLcB!>HDu2J+q5cw#LxAGeqoW8{!Qi;XE6wT6jcLz_t>!}M$sMxudiWmv)!ACPt z^#li_^UuzieU87@XzzZ`5e4S-A$$8*)WExFh^xO3mVMoL(`J`&D5}WJ2tVXWwFn#p z-j{Jbb9imXB>?KAc*`?RRCJBl-T8mqBrb?C@~!oN?Fu_CT1a{h5gAV{D3qqOQ%mmb z>}?)U+eAC{$2b;A-S>i(je=|QX}7&`Jgj|x;O|SoPT3L2qviu`A*ymGs6!6?Ico~v zQD~qorqlGZymfv%#CDVUm_d!xE1(xV>XZVyK$2K{oP*Bmy5(PmR3GxWpPBh`MSVx( zH$bji8u2C8W7=2~8+5^1rzbH2ta=WtlU_QWBUSj%P7e5?>AS>8X-{=jNh4r0*b#Js_ zR|#cy{$z7M%oVgm(D^7nB=pVQ@SX+m=c(ftD@*KV9n^#4x%RT2k_@jTgjH!@5|5e0 zBTVZ8V4u z4HN?ul)T)kMtE>&?Ody>#RgY2OeTq%(H)`QpCXqCpx$&puC22NS3PPyx)<1xNX>%> zCRv8DzSbr3wW@9e$4^?NubOam=10adODeVjMmgr+s&vXu>?vqGqUnI`ZXgwqX`}3W zR**hYx|ljkZu;3_h$f(oN>2#znj-W7{s%A(j*+6Ahp=fe(qo!9UV`#s$N@}OO+V=z zu%G&b@-+0rdB zobw~zCu3xD2{JdH&wy%PU!tZuc^Yrz``+(Qz{7TKfXwA_^dXJqf+acI=6Pu3z9p84 zBlLOe(aOwo|28R(5%-_C)j~NvolPx8%|^pB&pI-sg3<#^(_(>`aqLeGEy@tyXF~13 zI13>4TfhZ=yT~AG!rcStZDkpc#NX|9s7=$Pc@CcHR5 z*N)*4{zu6j0kh~9DKi;v4fQ{CO9N8!7?8C~AVJY4U6D!_P&Xi5*Df4+Zzifv6$Hm) zI!O`0wZdqrYpQIqSXyK9Fp}~~TFJ`m*vfFcuQDflaZU4h#S;H)r_Ic$u5MWyrYfpx zT`|AhbfR8mYe@idSkIX7z49rT*lQeg$Q5llA^Q9T6lUNmSYC}Q>lA6&=%0xdmap7W zmBb1^su96930G?_VEYrxAxBwEd@m_a3efV=Dfu%+Lqk4&Ucn^DQg8?eDkRB~FCOhO+xS)%%;D(2$gVPcXxLApMo zmpv4x&(s5m>qJQf>^VN4bFVK<>7f89k08@%5D@bemRP+Ye$T>C+-zgkf%(*bSnLoH zeHrY1IP&+&2!;xUYpw{|e@@x|m4C;|ix_tbi$Oa}hzljxig`am;VrwSkuC^14q&wd z_)40HHYfCCc5N)vJe7Ed6XjWBliAk6T$X$=yR7mw#lk0pq?074lcA#wCrd37@)*`>;NigG3X8t$zX>4OtQh{vqAAWp>f*GvFN* zZBOy5LcmU;@+^dqhb&!^5h+b7kDS+p(p{i<2I9k_qzHSXIOn~zg|v7{b>s8eE1i>r zx}y{#=YY4)bCATiWm?w?xyzkkP7&^OWEEIze@@RzX^-w>qNh+FZNeW0F|^tRuUa{0 zV(Cr)EnnGG378P;m&naA{=^VI+=7M{~%}t?o3G4$5?|$Cl zCpUCqUbv1-4_wHBCsIj`>)&R}aO;Y-i_=0A?&(4BVsLG+OLRG6Ves^G8#4BKyXSH9 z%ir_6zp(SY$Kdjd8G0cQEQP6XOfhsrDSIDINppQQODa*VL31IK0fIjSOKZ&0hXz=A zz_ALft77fTRAihkhi?7X5QKR0c|718-ZMn+re4by= z(imXv>VmBf$?keOdUu;IO*ntCnJwEy+v>b*9fSdDXp!x0f>F$``U7OgsA!?WsLy$^ zu{vcNTUC8%2xK{Chq}`SBoVoo)1~~R5CJcnVqpQhNCK?()j58)QA zC&81sH3#4kV--(GvHF7#Ci1~i!3X$HzO|k&lEO~?UZhR4f*%>o5fAD*VhESnr@_SP zR72urn7A{`F^8y%2SuCzvY?!1{))w_hW~MVH&*XX^58teN9lplPpnp8sRjlHbee`{Sxod+%$24pi~y zexGgY7X9DHvzt+aj(8P+PsclHHD~ttcmJ*0Z#~OL0tame?JDGa>tk+)sy9cI6r#S} zADay3bHG5iWXW*0PQ`Q8bJq&jN7?7s zO3usF&8~li+f({{cjIiHVj(eH7qn zXM;>w(~e3sd=Na}1{np&d-}JBbHm%f-)=}!mf>-$P5+_M`Rwk07JpxBIe!+ycqr4C8{L&Om)Jk?g6+9~s?w#94E+gR|8Y zR0inq0Tu-W*ka_$$IB7MqS}pu3}yBAVM#TQAsz z%y$$NFDtx{V9YU98Txnvxd4)iD-^!>wE3wEg(jD@#a)*Q10%)#oKP#}Dg^o9FuRf6E{Xmg`u8!e> zyDF+|fTs)fCao!A<-cxQjAl{iY&6d>wS+KvBP|gkne!L=rKBFQ0vb1oUdiW61YMjq z9>%{*gH>L?$o)%aU9`D!;+~O`FesDxkqHFv5}B^w6l{xNZf7Lapbw~>E)jTEgYEU1xK*{z~H7}wyHU8uN20k?S z`nr%wGfVUX#kzDY9aGWy%iGD`z>C2DkUXcpR9OO8r4QCt))~35Avj&nzx-g=;X83P zds=^AIxck6s`8hWEHi*tBByO}11;Pi=KLv8(t6u`Z*=)$ul|`ZP2kwHWqpb4TYxQ>)Dr^0oZO1r71lUnj{v}4=pAIw~{*^MYBa!0q(#u^qp9%3Ald2sTn(6QTU$6|-`*68hl zLE24B+3piu^RIk8^3miQe3S7b6;+Cj+2#kBTE6T#$0h;HLn*G%)h-P_^TRx{B+CZJ z@DIESqNxK>B#uF~Cj9=sHF5$y(Kr7|Vm3Ye;kJqTK5ur&e#%;s^OrGZnG9sqO?UyO z|GkOB#k&0SM8O7auN$TGCOd(*Jb|iC%7EL!aJ&BA?@(>pyuOoiFMB}nYc+kG9_9Z@ z=rl`9^Gtv#XS)?y7UR_gb?-InMjdQ6iB%c0jWEACnc-6wv2D2Z2*t*NF#^C#psHGC zY`stwMle%jd*pwCfx_1UcwvUqILuX5TFZjHa)u7acl^;vB^{ZeBL5hrmku^+ZFyr6 zZ5VEa+m-tfoMa9(+xCt!ONw1VU+KOVXR7wpR zgS>!;qfQjK$e!xNf6OZq?gPr0+HG=K0bj*iVkn3=Drf7`3jybrn{ZgwgY~4i1jGmY z0KQ7ryrJlx~l z{3YYMwJEeG2JV_FST1_z=`*Q0gtkImU}>)yVcqMs3N%BeU`(7l7vH~<*D*%X%iaa_ zpmqfc*|1rX-7v*+i~py!s$c8HatNoJmt_7?GxFN_#-y(dHC@b8I87n7ITWib zGBe3cpS~W0p}iZ`PMEF7?ASuc*c%QSfVulyKw z4uMV*=`yF=g0}KA-6aqDsu^&pptfL;pxy>H=`cT5#v=-6@-zKM^5U6 z3Q>_Q0hK^}S@OdqYiX`(1ShcE#Jg-rO|eU&^AJdwdDA+r)5YT$xUVVcaq*q_FPsY8 zBr7pCV-$IYbt%;*5^o|z_#dK;Aj#0(F%_i{M7PE~(gVlA^gi18^NLvcCwS!9W|s*g zepK{R74eq;xX_!Vg)8skHq0+Qu#Hn{4t7IIn8CP8jAZ$|11mI*K!H!K9_3;opR_-h ztZELD3Tu%?{ZTvX%ffWDR&7kf;=O8A87-A zZ%|zeAJ6&e56@0L*hHj60 zlDky2(!Zd19?i;S6F`5uVQ@5-@#Y`^y6A_g>y<8sZ!$Y5Rmv1mEEddJlR1pTr>_xRe$p2+ThS(2X}R#zzM{PxJ@UUVLI5 ze@gBR{%d6Jr82`8V9uH()+BnC?PRSs>jXyrhH%ELe}G8iDPaWO;bI2u2*KkTlQ?`L zny|{7E`+M-I_=7+KCS5xoBC2m1K$Xe41@Z!U!WN_mOt&CiD)&FV`0SpMh$zB=gB@m zda>g;FIQ5@6FsjdUgoxt6t*!>MVU$oO$}Sq)6?iVG!@!@ZZ9_2HM|d7D%Iiz$pZW(uKbgz6@T3nG~dpStBtMF_ij{+NDMkC*TV?_q_Rdd|skH#ru zy~)v((IgV#eARVYV}%8IJ0yBqTlN`d<%xm9=1A@8tD;`!YkizQmUgE~d`Vi`;CQv8 z;B&@p_FndwY*Fx7;&Sytsp3mzful~v=~vFZqPlx^wE!BYRL>EUXOYNcqRKgGPx4~X zI2mAeqB#$0N}6^A@v~`%hu`Yn##5^|8%gCv0C^vW8R0h9!_?J>OFH<>NQvSj&3bq7~#ATmj_ z>Fbc31QpIl*pyvli{4oX(-wZRXbrxk2aU4U%<#;MztMvpzWyddV%9^fsA zRmPstOzs*H2I|LwPvBPexO4v+r8=oE-C=c&ptkBmxlcBAH=zW?-^&Pg%F zz$oVR!tku(<}&0vWOm?ZSAHP)WSivMF!ckz)2burBBe*Y>hp@m9qMiUDQZEE?-C#X zYj@n>?}}ZV!}h9of!Zz|*7}Zp6nxDj5F7ykaHNv>ucGTGqIv*34s!Z%y3-88KTJKi zmO4)S48!M4+2oY)hOgk$QaHvBv!E|<+D#-8OtI=Qj*m%in{@Xb)_~<1C)3w3nKC8{twvkpHaFan&mzJ9EOQH8OTB-3fjkq_I%*VE_QFnmRDnk{_d@d7I(`0 z($@a(D>a*T@58~5({({9w_fYro*IPQf^`SA04||c?(F9fiqnJG2t^Mh#P7EJwI z@{o~M%Q52l{Ptij5eAkW#T1r;k|3%rH!O}{g9Bqrv^KGQF?KsDHJCfwFX0ncHEr%+ z1>?&=-CoWQ_fKmHHVqbmemOnP4()=2e@&OE3{E;^%-^lv3F2bC+EZbi{eQ-uXU1|8 z^1c!h2OJ7$F{OSzsfq*UjY+7OAi8;>JL;4^#J~x!D%qQvMxV*a`c0Dwoq=xo|V^Qby?2 zy^|vD29ElkcLtD?*>d2XpKcPv>?N-+FtiAC~f|Kz_qNg=EJ%`kI_YRI(qR6bS zxYus5t%HCiK~omgL!dScWR+wKx7~{mm}cf<>Vy-kXjKj;@6tB792?>PYo^4x{AgGT z2TwTWbMA=~DJ^Y#dU)}88HeKIGOKd(4*WhEqq8$grYeN-7v#C$a)5`|8@f4pCx){^ zVauUw`0Ii2@_G-iu*6PN8MP9xJ-64Q)9qq?i#Kn2X*oA<;TGQVY+x+cmpyU@W>aL9 z`d2ByVHScA(hx~Y+@wv-4MkCN&o~Br5_32_6cmCU7T2V4-f_B8oc#3$Wn+}1oFJlS zg2^U@;~;5xruFMYu?wW=;Ym|Ot()t8X|tuXqyff`{cy^Ky__pXL5-Vk7UWWm+;`jD zU3{nxLx$FeN&tM_p~3I;B4FCo8J7JY$TuQ&z|QJ#&gCly!S?wt!~N|kjK2jVtugA* zt%)B;E^iwu+1Wy))}s3~nhtudcmy2GY~FvjJ+DpX_iQ#Z2|WILkc+AeaVN}XpXJyd zUUT;RMO@y@ov9}x&byEavDd+bl=s%<6sM6zV1fZwX1%q(&v@JlsU67&5RfCQq7s=q zCPA0g0vu4!W}i$tiZXKVNfrOe<{6KoLQ;&>HrSDAc~u}X72*@;PB&Lq$7R1A>-Kg7 z!?xwL_7)9r*>FRliDe+CNFI4_yHncSJ79_e9l+Su{+tkJu2Zh@ol*~6x}n+&&rSy9HNy2n?GGYiJoiN-_HbSh>%v2L{*M3D z_*ia4a~M`<8nT7s79@{AYb!pL5L+q5_x3X+}-F*Ct#F;0|h!K|9@pUa_ zxuO;V^tDcLSL6G-PQ-7!k{k6rjIGn*W3>6p4G~t2PryjJtcRN3D*IHXbJfV8d)=_E zKA6c14J070tnNIOgh%PxI(tw%InClrliiW%4r7)^v81e)l9xGwBdu~R?yP4u4ZQ0q2?gH^_+-XoQWBur41vHDV zSuoO2q!BL_gI`S%r>o7a#$=+_jlrOVkBegP4CcXWW(L?pka5{M(P0AJ?B#*AKaUYV z371r>YHx!J%GRxfS~2ZO=8pm5{!ggbj7!0GN?d4v6KJ*Wi50wWNs-;&DV>t2-HYb% zT?lJ~k3huspbMuAVH->e(7v|*Cn5I-4KH+Arkjnzyy;6NYg8jGhsInzrPJ?RK%7li zv^ksa!B%6Uk9ul1*m-Q+8Sm`@K!KZDGq^+x?lhp7SN}3D4TKTLsKqLby7ZW!0|09` zWxEXbfSfPR2|&TM%eGRMDVAFeB$ zZR(7epGL2AwjM%sS@w)wQoNLs9Vu==Og(x@|e_WTlO(wfX3k|1Y! zv^x=xF9P{haL4eKVF;po_^lC`%=_IAXmC3FeaFlD1(c3+xYyI40H|h~Y|9G`=#zd> z{ysS*$_D&({eVTin42Q8jhmXh@%2^CAKI9$yDhz9m}Rj==Qs7rHKV``9-kl>1q5&SIYD?Qc zijC@0;Z?Me{!_i+hKncs_m|v%U#A{Nd}&in02d67%9#a{rn`1YGvbnxRHJjTb7k?A z!#9W>l@vjeKmc$*(`^Cm=*f3ZW#@ab5W)t{!OwDTuyVv`mt!_rl>IY(hLfx#A>$$Yj`PDx z+%BVbM5WtMQ(jlY-`^gGkgHy3fy&nE-1lt&KxF}8q#b_)r}7`kzz`#XMv8u`g*xYG_6UHO!`LMKN@K zzIMm_wi>kmeBBEmauiL+{cd#l{C>Y4|2E17xaC=WW@tceb(_k&^FY>X|EGB7!CGp( zsTH7gdP2L##OQFz^&2q$48X3R<&_Y>e_?Dt@W#~DQ*Of3QtAg(;C8E#{oN^_dMa(_ z<+u`W)w!Y=r#>!kQ{z9bcmcHK>btcDi~ZX&e6KIBwdonLxaw`f@uryM*jeb9qm5JA zAJd!CIIvt5=Ig04_+FZ8aVBIi*cEs^w}$7sG8?2+z%?dj?9;dXN9FBikM!ngvCfi* z)&zQqEVX1w*@vU<{|dMEk82d&8$*X&8`D5w>e=2Sc~Mue66Uk{ojerN|PkYcV4xx-?&nh$8j988^3cBu69~eC!9pA8jt` zb_C)pAg34R*iRhlWC1wrlKQixiMeTZyYYsdOTyL+33ntUU&y0e0Opy(s|CoTB$;mw zBuOz?3pPSvdWh(>hh{ON;guYf@a##g{GZKCNfIY4ms{hNaO|K{W_m}-8Lc*zykh_9 zT7JPnOWwN9{_n08{_S0>>uZ9m#o0T* zORjGpa|*Qc7fLlP4FSa;Qkkxpi$gC?7+z*Qja9?FC7q#IHk%aFxUJgdm6`UdmSs45 zl~XKXMj)R9Qeh%p_Wj^kax}yWh(FJu&he|1y?T7zXi`yv#|qRcP9}ypt1KBr7-m0% ztlp5`P!9cr78`||HRcx27k35ybx!yZv=QMl z?$(wKI02x~DxYl=={`H3I%x8Ny&BV(x`C3h&_toZ*F%zQ8Jt_tih5CmA4z3#4U%$n zjbhd=-s4h*WzeIE>@)|*yBCmTE_E8xWHHDk$~>Oij=Du%p#(p<= z-|Ms<`|5uS*t9IzLw1-_3F`MgV*(r;9}ec$#$LN9KF&gNzP8tU^s70GSTOD+5M9HT z6?V1EUODP-2ME_<2Xb77x>{EdId?A;stH_?e*`txo;OoY>-867%7wn6rxgZ`Qjsbc znIDW@WjmKk(aH$e!n%x=CgJ~HI+oA6ABPDdDV|DluIX(T#NJk$rmP}mFvR1YA|1RblGcPGduN9-SGG~ZfupZsC$ZW~Ca9>y7`8wH(abd}I+W~xxl(ic0jcqitvMcM`qi@uMe zCzraC$)YTK$L6v6rUWjFXzHor`Q~gQ2_(~hpaL=}gZEUk2e|(pm(0}|y3Hy^W{E;yoz3EE&{Rk|60De>7yD=;JU!H=F%#Mw@>+QU4fQwSplA*Ri+rC8sI|? z7eFUhp5*ML=kUKWG(X+8Our3&8_m1uR#-V*amAs0M8!UC7ls;?s1Qa{>~eX~P7VFh zUOCQU#iFz4c=D6`etq@2Eym|QBIY79jJu;OH?1k6bll-w^MJ^5#co4PM^0u%j-8A& zmxuj^(=&~t-{~c^s5O=c2;pP<#A5C4i^2?jF`gd5sG9SbBT9T1rS1a|G`F!%(131b zlANm6&r_8%#8IUkrxotQr^kqK0JIw7{ZX9oi@VyZKX92*-FLVB2%B3g?Lp zjdHK(Mw-k=Qe8o#i0Qa{0!;l57q^H_w`1#tLL(GrpJBM2v_uq`^Re$UtOe4Q^|~6^ z9lC{;{wevw!aLf|@3een%QF7`Mi)HOU7KoSwpeU6w3h3t@v~pMJQA%P&nuNXx8&Ba zFWBw`X~y8m|Ly5{jhh%6{6-UJPZs;0Ws=rk)X*KXIB0#E+ z*xWy@z6szz0_ZIs?mB+7cfWj|9Zq|lzmI^0)4bo?SLEMDY7#4@g@;dP{xigac~B!< zYPeMp0<7YNsH~!=#v1Q35SOn4Z6(qQ@j91K&V0E+e1aSchkD7kJIpc^4N%T+M7VUm zR)R%FnxOzS6c@jW*|7{tKvN&T6#pyN2H6=TVlMU)Be~LnYcudvg|W3s53Cih-A3ZP z+J!5QDt>wvDBhgMZdAWfV1$1=2ve23`?n_9HKdLWu|Y1W&lxZ7^8_{oR-KRdzWi2f z(YBY{yuDGnG6L9G=t!ufLRrtHb8;7HH|7>;uNDLJS)<5AjSZRW(juG-edm_Z35;!I z@ud<9oLuDuiM{00-vrz&{W${6i$vtlp+zp}ILmK36YiK~j6@d-fepf zgoU0jgLJZ{vm-^b>@QnGSqswBEke`-e=l$xX_pKAWF%8(KF&B1z&W0h3qiE_e>MSj>NV1c1m=A!BGzcpP?+E1!CzX)qUBng; z2P{Rd@fkQ-Qxw5qB?HYevSNspWWtz89#}wFF>4b>oG+axZTU2KF!*QnR1|BHF0@%E zv>jDp9TzH41x#)7Y>WvmNwL6u$amKpkwH<{`A&T{1|pY=mw{>~WS6QnFNIb1gs#l4aq+33S$7|O>z4C_{;dY3 zcT*@bX0zu(HDOt?WtvFY3I_0qPzXvL4)Bs;V)h|l(d)+{%@Se7{CU3rtMnmg%7dfW z3uGZ|>fR;49=OVp>b#7V7m0X36xp}q#x>tzou&4WWaJH5Hdy2LvKnx_;oMPirK+MG z7q7Aw<*`hMS|l!qCcz}Na;$`WS(se3R{qv*j?i6zuOm8Cj<$JTT$KU`u1VJoNH(> zbHA}P(d|xf9s578A0;yp_FuoJqdT97{Rxi(S|xcttPAGx(Z1NwXgA|yu)4+83me)O zh}|1%%NK(mcbCLhL7rTQ-naJ4$-Aa~N-@BF!9L9kz`->TQ_~U}KhbXj5w!|PP_S>m zz~nv+@4r7o5(&3&zppdDRravZm3azjtKKo^Ck1xxukO>3&NH!dhPNIoLLMpk`&S&* z_JiK8sjSTs+;i7BKaN-i_OiNVy}=seyfS1nDPwY>50pi zUNl~f)KvQy{WOaRjMRr;p@w=jPnJ2u{69?HvKeiTQ0}eRpKX7CggU+WqVQJfx3wX0 zl;$-0Be6p380>f=VZ&-g_UKC&y&ck6SSTGaulMW0fN|SeeISH>Zj%=Y>@*dYc|e_{ zdy9;H*_7y09(u@RdIz3wcYjjAq)@0jOJI92m?yT^(ro}xqBK1!|{u6WUqmD zb01%ZxGuIc^}a6#&>U{a55$`Ho&a$oTAK1+>yOS94<_=n%EXi^=C?kUHO|2677fJt zorJ&DJ(vRq(;_oiVSAKiJhbja4TrO>U@r3NIV(*QzBE;vO%?j@`I*)bsKx6i%QIc&j-KOE_E&SdA zG%zu`b`BM+LelQ;aH`5fNwOPR}@V2WM`i1PZ7)tk^`livm`3ai}X{(OO zV8HTROH4O^vX`URm&EK*I;)Q-TWEz>SIu{8ppR?D3zSz}Z(NX^MJ7-Atl-yz!T>&m zHRvw_L32NHxN^1&7l@r(^#;3PUx0nM@%y+pt!a4~FG$XuKrFW32)a@We3FuYL1(zY z)+cog3-gk6XhGu5E#sySO0m?wIz^7sUW@-|KHo#}Z3$H`1i=wV}5rK%g)f z%!Fp$)-sF9Nkck+Zolliz0j=wGQuWecbJ5chsuMMA_=!I@-vNk4VR+;1PbcO0{Oly za?m!{`h{0p1)d48oeY%cN_(9`P)tjWHn?4>9b^R7*7+qQT^ll?^d~Ib~?IM=o(TOGq?t8t55e8?QyW|=)2y2mDhh2mgj4!&+7Jmd7!GE@% zdl~zpHF@>$;A@A9#8VZ(gc@Bbf>C&6d#ek?gC*LrKU@DjWK+JrGvIWUk}Q}fZJUoV zSZG>lwY;~q@hW3=?2QOFn|bddBE`g;E)La~+Ow*at|W>A(m(Xy5mA;Mg@4`u!)JvK zqqF2(mPXN-j_Kvfh;xLpAwIh+uc)M7S4eqzg;iZ^%p){TCHYgsI`T6F1oFpYD}5k z$SxaD$4SNt^)!Nhy%eM3(@z;C9o%fIo4kCoX!*bJRVUL92OMViTfTK6;kZM6Dh`x zmaTQ!6X&k|H9w^a9z21~9G9kmbS}Bk>=$?SvL@SEq$|0XAZRka$U0Lh#-X3S$2vQT95Q zr-!U<^O~xe)Rzw0c+bp^LdH9Fb=m+A$$<_9T`EwBBn3^y8&L(rDrbJ#U>nttI@^|` zUTfa65wxJy<0ZDTuO2lLwYfAlxe~aCnv3&-?@hLq`5pRR^+=7Iyw8QM=p83fRc*qu zhJWbusZfb}Rueecth^Q;x;_#=auB0qt8BF$i(=^=F|KrAthdS5bYJTKE#IIzKM^#- zNoy+=7!>pAs^_F&yjS)c-VqLj8_}@SE{CqL0%7yjq78L}}9^aYQam-e`i71g! z(HYU3Xlh~+Bg3RVq7964Z_@MnWR;zeBN3Ik1`cN&V4rU^s+lbsY;R^t*NvT8<;6)FrgLY3*T75 zAAuVQaNNFE>8(kD_rD?M7E7X8$aiLe{uFF9DQ%jp7u~Ysk`kba1g%LEBE$a|-hSmPaptEE@FMr1>|@?B*|rmZP?m~}U3+7eJNt?{+K4zb$~lz2}O zzL>O?&mImpo6cTSJZQ^ece8r{Qh+2o-U|P@zo{@GG#Pvc^Tw5@(y_>2`?yRa)5&65 zV9P`8rlfOzMs0aWvY`Fy~UeZ7dzjT7E))gC@0dm(iQF>peOV3Sv%Iv(3pptvPiX`Y3k6Yo>8NW(fxk&TQCZg&%--ivJA0nIvAs6MQ zfp-O}MLVp`tRY_@>w$7&5?L>&*er#nm_4jIlNfDvPF)O7r%_eMO85M0GE+wDh4d=2 z2A{~@DNN*ft%Epka?q1KTZ@A)Duzz$Q(9!~LTVH~0OK5USSw~i=0aAG99Pr-6XAXp z(lI>WrVA$3JOn(`3y4z`31%FVKV%!g-b!<6Uk6BnoFmhX?iB>pD(xAA&f<{NW%3E< zypyn}PuhN%b>1H{^^TBis-dh7&inND>?sQXtHM9SC;I72GXm^yL9FYc&O;tr#!V5kh|M~5-ohO!m@Wn`!E&M&N$K$j!nM_LuKeu_wK_5Q@ z$Eg@za70$=suTdE@C&)F6#R->`^O`P>O$7ByI`4^VO=J|qegKVEmVBYwE@#_)`8MS_gYo%7=T-43TPIVF%9$a!dL^Pc0%!Jc=FV}(D9|NCfd+*1La<; zq9P=5p{(Yu2DkGT?OA1~sJQcv4nH*5XdXs zkL2`VJ0RkX9VCtNxp{h^;|mAF)1uj$X>#-WG6gFPq;9x2>| z&I$>3IfUJkJc1(}22mkQ9U*X5%3(AqJx%bbv&*&3Jfn-ZHsL5g7kcNYz^F*A<^Jv% zTG@`F1LdJrb!e?sxMKnU^U-l>Gnfo2x7AbQN!~me`D-#{Fe|0X-&S!-VozQ9IIDGi zI)a>{AvX|muIZzDe)9WFQ_VFIu-#R<)g{<(%m~w8E;fvU92SU?#-D3X>{CRrB@MnC zfdm}?Y5aMcrlO?pI>nOGFvWkVTQ<(AXwK)t`$4cybX#*xAr_cAE|}M8w%y!)MFvoO zj9tk0Lfv{%p3&gF#46)&8w1=E1(LB8Ye_>BWj{Yos(eDW0&8(Qw9jjsTf8{ikV`-D z{L#KLHywlr?WZ$L@sYTTHj*pAp0SjF0Mm*0E^)EWWuzLI5P5}%yi>U%{Ix^C)ymy+ zU0zq+nK;}?_NMfg#g@HJ^?5xTQ1vdc9um=aMH*1Ti4z?H3RFpxtJcFX(bWx!?lX2R_0$0^gDo)B9(M zTt7^R>mO3!6*+8)cMc-Bg&Y`yukljp$igWL5%T`m0bb|@Vc$gL92&jZm!pwb%D0oN z3eVMAcBo~hxyps`vip)ca}D9Ml9r_neJgL(nE&C?)o;XiyuW}%CEKSntR-zPP|J$F zQ7^0}D+%M2O{G6dXetT0m&bj3Qb>v$V-4q#;rz6dD0RC{dK#e=0$m4n-z}wf;413Q zDjsHMe9o>|t0>8hPw^D~ys0W|{h>ma_t{5#aREX4*HuIBzUy};&R)zX6LL;7Bx(uV zY9aYEgp|V*0=FTdb$c)J(;1DnP`p4yDvpv&b{8vk9f2LSbX@b1{FxQ%pj%&~CNjMBe7!sIaaJHk8|NG=`7anas> z<*2^~NBkezT_yzlvNO2FBwV;q_@hr=qaV K(pock$knNoc8{nNR*hE!eQ+=-yjN zldS&ngd@6p*}*#2!2LUIxfAq(*)Uz=N*D3B%l4gj$5<)6&Zyq5EFuM=dO1!XbX;suO!|fx{B6`ELXQDG?%~Er=+J z_}^)8&M#b@JwO3oAn{;FFVFuD1@Lb)>i@ximHZp_`k(w)S$XMy_^0En) zO7?-`BUG`|r+Z{N!tbfGAr5y9^_K4sPCp-1>EwNlh<3r!roc<(f{TDh7wBAY^@uno zJxiCUptLw4zUMq);y&@RM`DS0v#t=$+Ihpa=jD{}O{j0Wd!Le#5nV;ZpKo7!)U;E5 zS+VTpxhCFkOx$3hO0F@>t}X%D2M5op<;LI8R+LMVY!h3SCadi>BH3{d4P=@Vr(o#8 zi~v0AfYM7R9qkqC!A#3}+OLi^)8%&|Vy*23@#`kyTz|E!uLgqV2e3jYq;`(wV~!8f vXZgjHYb