From 0d34281949b2672a0a7b199db47d0d0193f57426 Mon Sep 17 00:00:00 2001 From: Keenan Brock Date: Tue, 27 Jun 2023 16:31:10 -0400 Subject: [PATCH 1/4] comments on passing times around --- app/models/metric/ci_mixin/capture.rb | 4 ++++ app/models/metric/finders.rb | 4 ++++ app/models/vim_performance_state.rb | 2 ++ 3 files changed, 10 insertions(+) diff --git a/app/models/metric/ci_mixin/capture.rb b/app/models/metric/ci_mixin/capture.rb index e225bb532bf..aab039f249d 100644 --- a/app/models/metric/ci_mixin/capture.rb +++ b/app/models/metric/ci_mixin/capture.rb @@ -89,6 +89,10 @@ def calculate_gap(interval_name, start_time) end end + # @param interval_name ["realtime", "hourly", "historical"] + # @param start_time [String|nil] start time for historical capture (nil for all other captures) + # @param end_time [String|nil] end time for historical capture (nil for all other captures) + # @param metrics_capture [MetricCapture] def just_perf_capture(interval_name, start_time, end_time, metrics_capture) log_header = "[#{interval_name}]" log_time = '' diff --git a/app/models/metric/finders.rb b/app/models/metric/finders.rb index 2ef204f8bfa..4359dba9cea 100644 --- a/app/models/metric/finders.rb +++ b/app/models/metric/finders.rb @@ -1,9 +1,11 @@ module Metric::Finders + # @param hour [String] def self.find_all_by_hour(resource, hour, interval_name) start_time, end_time = hour_to_range(hour) find_all_by_range(resource, start_time, end_time, interval_name) end + # @param day [String|Time] prefer Time def self.find_all_by_day(resource, day, interval_name, time_profile) start_time, end_time = day_to_range(day, time_profile) find_all_by_range(resource, start_time, end_time, interval_name) @@ -37,12 +39,14 @@ def self.find_all_by_range(resource, start_time, end_time, interval_name) # Helper methods # + # @param hour [String] def self.hour_to_range(hour) start_time = hour end_time = "#{hour[0..13]}59:59Z" return start_time, end_time end + # @param [String|Time] day prefer Time def self.day_to_range(day, time_profile) day = Time.parse(day) if day.kind_of?(String) day = day.in_time_zone(time_profile.tz_or_default) diff --git a/app/models/vim_performance_state.rb b/app/models/vim_performance_state.rb index b329c64768b..6357cbb762f 100644 --- a/app/models/vim_performance_state.rb +++ b/app/models/vim_performance_state.rb @@ -46,6 +46,8 @@ class VimPerformanceState < ApplicationRecord # => host_sockets (derive from assoc_ids) # TODO: do a single query for the finds + # @param objs [Array[Object]|Object] MetricsCapture#target - all should be the same object class + # @returns [Array[VimPerformanceState]|VimPerformanceState] return an array if an array was passed in # NOTE: a few calls (with a single object) do use the return and expect a single result def self.capture(objs) ts = Time.now.utc From 5280baf5377eb010d56a8cd7d45d35cc2db2d82a Mon Sep 17 00:00:00 2001 From: Keenan Brock Date: Fri, 14 Jul 2023 20:47:05 -0400 Subject: [PATCH 2/4] vim_performance_state_for_ts(Time) defaulting to passing time into the method. Places calling it, ensure that Fixing: sometimes we were passing non iso8061 into the method so it was not finding the cached VimPerformanceState records | ms | bytes | objects |query | qry ms | rows |` comments` | ---:| ---:| ---:| ---:| ---:| ---:| --- | 1,699.1 | 19,618,021* | 283,526 | 9 | 1,519.6 | 79 |`before` | 1,664.1 | 15,672,327* | 225,826 | 5 | 1,550.8 | 75 |`after-fetch-time` --- .../chargeback/consumption_with_rollups.rb | 2 +- app/models/metric/ci_mixin/state_finders.rb | 25 +++++++++++++------ app/models/metric/rollup.rb | 7 +++++- .../metric/ci_mixin/state_finders_spec.rb | 6 ++--- 4 files changed, 28 insertions(+), 12 deletions(-) diff --git a/app/models/chargeback/consumption_with_rollups.rb b/app/models/chargeback/consumption_with_rollups.rb index b826bd3b04f..453133edce4 100644 --- a/app/models/chargeback/consumption_with_rollups.rb +++ b/app/models/chargeback/consumption_with_rollups.rb @@ -54,7 +54,7 @@ def chargeback_container_labels def container_tag_list_with_prefix if resource.kind_of?(ContainerImage) - state = resource.vim_performance_state_for_ts(timestamp.to_s) + state = resource.vim_performance_state_for_ts(timestamp) image_tag_name = "#{state.image_tag_names}|" if state image_tag_name.split("|") diff --git a/app/models/metric/ci_mixin/state_finders.rb b/app/models/metric/ci_mixin/state_finders.rb index f5638826107..4140a2eb009 100644 --- a/app/models/metric/ci_mixin/state_finders.rb +++ b/app/models/metric/ci_mixin/state_finders.rb @@ -1,19 +1,30 @@ module Metric::CiMixin::StateFinders + # load from cache or create a VimPerformanceState for a given timestamp + # + # for a cache: + # use preload to populate vim_performance_states associations + # this loads all records + # the cache is indexed by a Time object + # used by Metric.rollup / rollup_hourly + # preload_vim_performance_state_for_ts_iso8601 to populate @states_by_ts + # contains a subset, typically top of the hour and the timestamp of interest + # the cache is indexed by a String in iso8601 form + # used by: CiMixin::Processing#perf_process + # @param ts [Time|String] prefer Time def vim_performance_state_for_ts(ts) + ts = Time.parse(ts).utc if ts.kind_of?(String) + ts_iso = ts.utc.iso8601 return nil unless self.respond_to?(:vim_performance_states) @states_by_ts ||= {} - state = @states_by_ts[ts] + state = @states_by_ts[ts_iso] if state.nil? - # TODO: vim_performance_states.loaded? works only when doing resource.vim_performance_states.all, not when loading - # a subset based on available timestamps + # using preloaded vim_performance_states association if vim_performance_states.loaded? # Look for requested time in cache - t = ts.to_time(:utc) - state = vim_performance_states.detect { |s| s.timestamp == t } + state = vim_performance_states.detect { |s| s.timestamp == ts } if state.nil? - # Look for state for current hour in cache if still nil because the - # capture will return a state for the current hour only. + # Look for state for current hour in cache t = Metric::Helper.nearest_hourly_timestamp(Time.now.utc).to_time(:utc) state = vim_performance_states.detect { |s| s.timestamp == t } end diff --git a/app/models/metric/rollup.rb b/app/models/metric/rollup.rb index aa433fe0da4..1e936267035 100644 --- a/app/models/metric/rollup.rb +++ b/app/models/metric/rollup.rb @@ -266,8 +266,13 @@ def self.rollup_realtime_perfs(obj, rt_perfs, new_perf = {}) new_perf end + # @param obj parent object + # @param timestamp [Time] for hourly, time is at the beginning of the hour + # @param interval_name ["realtime", "hourly", "historical"] + # @param assoc [Symbol] name of the association to rollup def self.rollup_child_metrics(obj, timestamp, interval_name, assoc) - ts = timestamp.kind_of?(Time) ? timestamp.utc.iso8601 : timestamp + timestamp = Time.parse(timestamp).utc if timestamp.kind_of?(String) + ts = timestamp.utc.iso8601 recs = obj.vim_performance_state_association(timestamp, assoc).to_a result = {} diff --git a/spec/models/metric/ci_mixin/state_finders_spec.rb b/spec/models/metric/ci_mixin/state_finders_spec.rb index a4ed1334b16..c6fd0f0a500 100644 --- a/spec/models/metric/ci_mixin/state_finders_spec.rb +++ b/spec/models/metric/ci_mixin/state_finders_spec.rb @@ -41,7 +41,7 @@ expect do expect(region.vim_performance_state_association(timestamp, :ext_management_systems)).to eq([ems1]) - end.to make_database_queries(:count => 2) # TODO: vps caching (another PR) will change to 1 + end.to make_database_queries(:count => 1) end it "fetches a second timestamp" do @@ -104,8 +104,8 @@ expect(image).to receive(:perf_capture_state).never expect do - expect(image.vim_performance_state_for_ts(timestamp)).to eq(vps_now) # TODO: should be vps - end.to make_database_queries(:count => 0) + expect(image.vim_performance_state_for_ts(timestamp)).to eq(vps) + end.not_to make_database_queries end it "falls back to cached now" do From 5a9de94769707d4410a8063476fd9c4d56e86f06 Mon Sep 17 00:00:00 2001 From: Keenan Brock Date: Thu, 6 Jul 2023 20:48:29 -0400 Subject: [PATCH 3/4] Don't lookup previously created VimPerformanceState wanted to create specs around vim_performance_state_association and hit a tangent. This already cached newly created vim_performance_state records when one did not exist in the db but it never looked for that value in the local cache. now it looks that value up --- app/models/metric/ci_mixin/state_finders.rb | 7 +++++-- spec/models/metric/ci_mixin/state_finders_spec.rb | 6 +++--- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/app/models/metric/ci_mixin/state_finders.rb b/app/models/metric/ci_mixin/state_finders.rb index 4140a2eb009..8fee49425ba 100644 --- a/app/models/metric/ci_mixin/state_finders.rb +++ b/app/models/metric/ci_mixin/state_finders.rb @@ -10,7 +10,7 @@ module Metric::CiMixin::StateFinders # contains a subset, typically top of the hour and the timestamp of interest # the cache is indexed by a String in iso8601 form # used by: CiMixin::Processing#perf_process - # @param ts [Time|String] prefer Time + # @param ts [Time|String] beginning of hour timestamp (prefer Time) def vim_performance_state_for_ts(ts) ts = Time.parse(ts).utc if ts.kind_of?(String) ts_iso = ts.utc.iso8601 @@ -25,9 +25,12 @@ def vim_performance_state_for_ts(ts) state = vim_performance_states.detect { |s| s.timestamp == ts } if state.nil? # Look for state for current hour in cache - t = Metric::Helper.nearest_hourly_timestamp(Time.now.utc).to_time(:utc) + ts_iso_now = Metric::Helper.nearest_hourly_timestamp(Time.now.utc) + t = ts_iso_now.to_time(:utc) state = vim_performance_states.detect { |s| s.timestamp == t } end + # look for state from previous perf_capture_state call + state ||= @states_by_ts[ts_iso_now] else state = @states_by_ts[Metric::Helper.nearest_hourly_timestamp(Time.now.utc)] state ||= vim_performance_states.find_by(:timestamp => ts) diff --git a/spec/models/metric/ci_mixin/state_finders_spec.rb b/spec/models/metric/ci_mixin/state_finders_spec.rb index c6fd0f0a500..089220b879e 100644 --- a/spec/models/metric/ci_mixin/state_finders_spec.rb +++ b/spec/models/metric/ci_mixin/state_finders_spec.rb @@ -10,8 +10,8 @@ let(:storage1) { FactoryBot.create(:storage) } let(:storage2) { FactoryBot.create(:storage) } - let(:ts_now) { Time.now.utc.beginning_of_hour.to_s } - let(:timestamp) { 2.hours.ago.utc.beginning_of_hour.to_s } + let(:ts_now) { Time.now.utc.beginning_of_hour } + let(:timestamp) { 2.hours.ago.utc.beginning_of_hour } describe "#vim_performance_state_association" do let(:c_vps_now) { create_vps(image, ts_now, :containers => [container1, container2]) } @@ -159,7 +159,7 @@ it "creates (and caches) a value when now isn't cached" do rec_states = VimPerformanceState.where(:timestamp => [ts_now, timestamp]) MiqPreloader.preload(image, :vim_performance_states, rec_states) - expect(image).to receive(:perf_capture_state).twice.and_return(vps_now) # fix + expect(image).to receive(:perf_capture_state).once.and_return(vps_now) expect do expect(image.vim_performance_state_for_ts(timestamp)).to eq(vps_now) From e6268fc9d71f7c4ad3c0aadd41f9bc5e188d3dde Mon Sep 17 00:00:00 2001 From: Keenan Brock Date: Fri, 7 Jul 2023 10:24:40 -0400 Subject: [PATCH 4/4] vim_performance_state_for_ts - don't find(now) since perf_capture_state does a find for now, not reason to try and find it first have tried to remove this extra query a few times. previous attempts deleted this line. this one is different as we added the unless. there were a few cases that we do want a find here. (luckily there are tests around this) --- app/models/metric/ci_mixin/state_finders.rb | 7 +++++-- spec/models/metric/ci_mixin/state_finders_spec.rb | 9 +++++++++ 2 files changed, 14 insertions(+), 2 deletions(-) diff --git a/app/models/metric/ci_mixin/state_finders.rb b/app/models/metric/ci_mixin/state_finders.rb index 8fee49425ba..0f59ff9068a 100644 --- a/app/models/metric/ci_mixin/state_finders.rb +++ b/app/models/metric/ci_mixin/state_finders.rb @@ -32,8 +32,11 @@ def vim_performance_state_for_ts(ts) # look for state from previous perf_capture_state call state ||= @states_by_ts[ts_iso_now] else - state = @states_by_ts[Metric::Helper.nearest_hourly_timestamp(Time.now.utc)] - state ||= vim_performance_states.find_by(:timestamp => ts) + ts_iso_now = Metric::Helper.nearest_hourly_timestamp(Time.now.utc) + state = @states_by_ts[ts_iso_now] + unless ts_iso_now == ts_iso + state ||= vim_performance_states.find_by(:timestamp => ts) + end end state ||= perf_capture_state @states_by_ts[state.timestamp.utc.iso8601] = state diff --git a/spec/models/metric/ci_mixin/state_finders_spec.rb b/spec/models/metric/ci_mixin/state_finders_spec.rb index 089220b879e..9fdecaf7d00 100644 --- a/spec/models/metric/ci_mixin/state_finders_spec.rb +++ b/spec/models/metric/ci_mixin/state_finders_spec.rb @@ -93,6 +93,15 @@ expect(image.vim_performance_state_for_ts(timestamp)).to eq(vps_now) end.not_to make_database_queries end + + it "doesn't search db for now since perf_capture_state will do that" do + expect(image).to receive(:perf_capture_state).once.and_return(vps_now) + + expect do + expect(image.vim_performance_state_for_ts(ts_now)).to eq(vps_now) + end.to make_database_queries(:count => 0) + expect { image.vim_performance_state_for_ts(ts_now) }.not_to make_database_queries + end end # ci_mixin/processing.rb uses this