ManageIQ/manageiq

View on GitHub
tools/log_processing/perf_timings.rb

Summary

Maintainability
A
0 mins
Test Coverage
#!/usr/bin/env ruby

RAILS_ROOT = File.expand_path(File.join(__dir__, %w[.. ..]))
require 'manageiq/gems/pending'
require 'miq_logger_processor'

logfile = ARGV.shift if ARGV[0] && File.file?(ARGV[0])
logfile ||= File.join(RAILS_ROOT, "log/evm.log")
logfile = File.expand_path(logfile)

$outdir = ARGV.shift if ARGV[0] && File.directory?(ARGV[0])
$outdir ||= File.dirname(logfile)
$outdir.chomp!("/")
$outdir.chomp!("\\")
$outdir = File.expand_path($outdir)

require 'csv'

def dump_csv(type, hashes)
  output = "#{$outdir}/#{type}.csv"
  if hashes.empty?
    puts "No #{type} data points found."
    File.truncate(output, 0) if File.exist?(output)
  else
    puts "#{hashes.length} #{type} data points found."

    keys = hashes[0].keys
    keys.delete_if { |k, _v| [:time, :total_time].include?(k) }
    keys = keys.sort_by(&:to_s)
    keys = keys.unshift(:time)
    keys += [:unaccounted, :total_time]

    graph_data = []
    CSV.open(output, "w") do |csv|
      graph_data << keys[0...-1].collect(&:to_s)
      csv << keys
      hashes.each do |h|
        values = h.values_at(*keys)

        # Calculate unaccounted time
        values[-2] = values[-1].to_f - values[1...-2].inject { |sum, v| sum.to_f + v.to_f }

        graph_data << values[0...-1].collect { |v| v.kind_of?(String) ? v : (v / values[-1] * 100) }
        csv << values
      end
    end

    MiqLoggerProcessor.to_png(graph_data, :outfile => "#{$outdir}/#{type}.png", :title => type.to_s, :graph_type => :stacked)
  end
end

t = Time.now
puts "Processing file..."

all_timings = Hash.new { |k, v| k[v] = [] }
vim_collect_timings = {}

MiqLoggerProcessor.new(logfile).each do |line|
  next unless line =~ /MIQ\((Vm|Host|Storage|EmsCluster|ExtManagementSystem|MiqEnterprise)\.(vim_collect_perf_data|perf_capture_?[a-z]*|perf_process|perf_rollup)\).+Timings:? (\{.+)$/

  target, method, timings = $1, $2, $3

  target.downcase!
  timings = eval(timings)
  key = "#{target}_#{method}".to_sym

  # Handle capture timings which are split over two nearly subsequent lines.
  case method
  when "vim_collect_perf_data"
    timings.delete(:total_time)
    vim_collect_timings[line.pid] = timings
    next
  when "perf_capture"
    unless target == "storage"
      prev_timings = vim_collect_timings.delete(line.pid)
      next if prev_timings.nil?

      timings = prev_timings.merge(timings)
    end

    timings.delete_if { |k, _v| [:start_range, :end_range, :num_vim_queries, :num_vim_trips, :collect_metrics].include?(k) }
  end

  timings[:time] = line.time
  all_timings[key] << timings
end

puts "Processing file...Complete (#{Time.now - t}s)"

puts "Dumping CSVs..."
all_timings.each { |type, hashes| dump_csv(type, hashes) }
puts "Dumping CSVs...Complete"