Project

General

Profile

« Previous | Next » 

Revision c30fd6f2

Added by Lukas Zapletal almost 6 years ago

Fixes #23808 - monotonic timer to measure durations

View differences:

app/controllers/home_controller.rb
# check for exception - set the result code and duration time
def exception_watch(&block)
start = Time.now.utc
start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
result = {}
begin
yield
result[:result] = 'ok'
result[:status] = :ok
result[:version] = SETTINGS[:version].full
result[:db_duration_ms] = ((Time.now.utc - start) * 1000).round.to_s
result[:db_duration_ms] = ((Process.clock_gettime(Process::CLOCK_MONOTONIC) - start) * 1000).round.to_s
rescue => e
result[:result] = 'fail'
result[:status] = :internal_server_error
app/services/foreman/telemetry_helper.rb
end
# time spent in a block as histogram, in miliseconds by default
def telemetry_duration_histogram(name, scale = 1000, tags = {})
def telemetry_duration_histogram(name, scale = 1000, tags = {}, results = nil)
case scale
when :ms, :msec, :miliseconds
scale = 1000
......
when :min, :minutes
scale = 1 / 60
end
before = Time.now.to_f
before = Process.clock_gettime(Process::CLOCK_MONOTONIC)
yield
ensure
after = Time.now.to_f
telemetry_observe_histogram(name, (after - before) * scale, tags)
after = Process.clock_gettime(Process::CLOCK_MONOTONIC)
duration = (after - before) * scale
telemetry_observe_histogram(name, duration, tags)
results[name] = duration if results
end
end
app/services/report_importer.rb
class ReportImporter
include Foreman::TelemetryHelper
delegate :logger, :to => :Rails
attr_reader :report, :report_scanners
......
end
def import
start_time = Time.now
logger.debug { "Processing report: #{raw.inspect}" }
create_report_and_logs
telemetry = {}
telemetry_duration_histogram(:report_importer_create, :ms, {type: self.class.name}, telemetry) do
create_report_and_logs
end
if report.persisted?
imported_time = Time.now
host.refresh_statuses(statuses_for_refresh)
refreshed_time = Time.now
logger.info("Imported report for #{name} in #{(imported_time - start_time).round(2)} seconds, status refreshed in #{(refreshed_time - imported_time).round(2)} seconds")
telemetry_duration_histogram(:report_importer_refresh, :ms, {type: self.class.name}, telemetry) do
host.refresh_statuses(statuses_for_refresh)
end
create = telemetry[:report_importer_create].try(:round, 1)
refresh = telemetry[:report_importer_refresh].try(:round, 1)
logger.info("Imported report for #{name} in #{create} ms, status refreshed in #{refresh} ms")
end
end
......
report_scanners.each do |scanner|
break if scanner.scan(report, logs)
end
logger.debug "Changes after scanning: #{report.changes.inspect}"
logger.debug { "Changes after scanning: #{report.changes.inspect}" }
end
private
......
users.select { |user| Host.authorized_as(user, :view_hosts).find(host.id).present? }
owners.concat users
if owners.present?
logger.debug "sending alert to #{owners.map(&:login).join(',')}"
logger.debug { "sending alert to #{owners.map(&:login).join(',')}" }
MailNotification[mail_error_state].deliver(report, :users => owners.uniq)
else
logger.debug "no owner or recipients for alert on #{name}"
logger.debug { "no owner or recipients for alert on #{name}" }
end
end
end
config/initializers/5_telemetry_metrics.rb
telemetry.add_counter(:importer_facts_count_processed, 'Number of facts processed (added, updated, deleted) per importer type', [:type, :action])
telemetry.add_counter(:importer_facts_count_interfaces, 'Number of changed interfaces per importer type', [:type])
telemetry.add_histogram(:ldap_request_duration, 'Total duration of LDAP requests')
telemetry.add_histogram(:report_importer_create, 'Total duration of report import creation', [:type])
telemetry.add_histogram(:report_importer_refresh, 'Total duration of report status refresh', [:type])
lib/tasks/convert.rake
ActiveRecord::Base.establish_connection(:production)
skip_tables = ["schema_info", "schema_migrations"]
(ActiveRecord::Base.connection.tables - skip_tables).each do |table_name|
time = Time.now
time = Process.clock_gettime(Process::CLOCK_MONOTONIC)
ProductionModelClass.establish_connection(:production)
ProductionModelClass.table_name = table_name
......
end
DevelopmentModelClass.connection.execute(sql) if sql.present?
print "#{count} records converted in #{Time.now - time} seconds\n"
print "#{count} records converted in #{Process.clock_gettime(Process::CLOCK_MONOTONIC) - time} seconds\n"
end
end
end
lib/tasks/trends.rake
desc 'Reduces amount of points for each trend group'
task :reduce => :environment do
start = Time.now
start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
trends = Trend.pluck(:id)
trends_count = trends.length
......
TrendCounter.unscoped.where(interval_start: nil).delete_all
puts "It took #{Time.now - start} seconds to complete" unless Rails.env.test?
puts "It took #{Process.clock_gettime(Process::CLOCK_MONOTONIC) - start} seconds to complete" unless Rails.env.test?
end
end

Also available in: Unified diff