chef-hog.rb

#!/usr/bin/env ruby
require 'time'
require 'pp'

RED    = "\e[31m"
GREEN  = "\e[32m"
YELLOW = "\e[33m"
CLEAR  = "\e[0m"
BOLD   = "\e[1m"

class String
  def red(bold = false)
    colorize(RED, bold)
  end

  def green(bold = false)
    colorize(GREEN, bold)
  end
  
  def yellow(bold = false)
    colorize(YELLOW, bold)
  end

  def colorize(color, bold)
    colorized = color + self.to_s + CLEAR
    bold ? BOLD + colorized : colorized
  end
end

logfile = ARGV[0]

if logfile.nil? || !File.exist?(logfile)
  STDERR.puts "Usage: #{File.basename($0, '.rb')} <chef-log>"
  exit 1
end

slow_steps = []
allcode    = []

last_time = nil
last_line = nil

IO.foreach(logfile) do |l|
  next if l.strip.chomp.empty? || l !~ /^\[/

  time = Time.parse(l.split(/\s/)[0])

  if last_time.nil? || time - last_time <= 1
    last_time = time
    last_line = l
  else
    slow_steps << { last_line.split()[2..-1].join(" ") => [time - last_time, time] }
    last_line = l
    last_time = time
  end

  allcode << l
end

tstart = Time.parse(allcode.first.split(/\n/)[0])
tend  = Time.parse(allcode.last.split(/\n/)[0])

puts
puts "Discarded steps:       #{allcode.count - slow_steps.count}"
puts "Total steps:           #{allcode.count}"
puts "Total Chef run time:   #{(tend - tstart).to_i}s"
puts

if ARGV.include?("--sort")
  slow_steps.sort! { |a,b| a.values.first[0] <=> b.values.first[0] }
end

slow_steps.each do |h|
  secs      = "#{h.values.first[0].to_i.to_s}s"
  time      = h.values.first[1]
  step_time = (time - tstart).to_i.to_s

  str  = h.keys.first
  str  = str.length > 72 ? (str[0..72] + "...") : str

  puts "[ " + "#{step_time.yellow(true)} -> #{secs.red(true)}".ljust(38) + \
       "]" + " #{str}"
end