class Nanoc::CLI::CompileListeners::TimingRecorder

Attributes

filters_summary[R]
outdatedness_rules_summary[R]
phases_summary[R]
stages_summary[R]

Public Class Methods

enable_for?(_command_runner, _site) click to toggle source

@see Listener#enable_for?

# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 11
def self.enable_for?(_command_runner, _site)
  Nanoc::CLI.verbosity >= 1
end
new(reps:) click to toggle source

@param [Enumerable<Nanoc::Core::ItemRep>] reps

# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 16
def initialize(reps:)
  @reps = reps

  @stages_summary = DDMetrics::Summary.new
  @phases_summary = DDMetrics::Summary.new
  @outdatedness_rules_summary = DDMetrics::Summary.new
  @filters_summary = DDMetrics::Summary.new
  @load_stores_summary = DDMetrics::Summary.new
end

Public Instance Methods

start() click to toggle source

@see Listener#start

# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 27
def start
  on(:stage_ran) do |duration, klass|
    @stages_summary.observe(duration, name: klass.to_s.sub(/.*::/, ''))
  end

  on(:outdatedness_rule_ran) do |duration, klass|
    @outdatedness_rules_summary.observe(duration, name: klass.to_s.sub(/.*::/, ''))
  end

  filter_stopwatches = {}

  on(:filtering_started) do |rep, _filter_name|
    stopwatch_stack = filter_stopwatches.fetch(rep) { filter_stopwatches[rep] = [] }
    stopwatch_stack << DDMetrics::Stopwatch.new
    stopwatch_stack.last.start
  end

  on(:filtering_ended) do |rep, filter_name|
    stopwatch = filter_stopwatches.fetch(rep).pop
    stopwatch.stop

    @filters_summary.observe(stopwatch.duration, name: filter_name.to_s)
  end

  on(:store_loaded) do |duration, klass|
    @load_stores_summary.observe(duration, name: klass.to_s)
  end

  on(:compilation_suspended) do |rep, _target_rep, _snapshot_name|
    filter_stopwatches.fetch(rep).each(&:stop)
  end

  on(:compilation_started) do |rep|
    filter_stopwatches.fetch(rep, []).each(&:start)
  end

  setup_phase_notifications
end
stop() click to toggle source

@see Listener#stop

# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 67
def stop
  print_profiling_feedback
end

Protected Instance Methods

print_ddmemoize_metrics() click to toggle source
print_profiling_feedback() click to toggle source
print_table(rows) click to toggle source
print_table_for_summary(name, summary) click to toggle source
print_table_for_summary_duration(name, summary) click to toggle source
setup_phase_notifications() click to toggle source
# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 73
def setup_phase_notifications
  stopwatches = {}

  on(:phase_started) do |phase_name, rep|
    stopwatch = stopwatches[[phase_name, rep]] = DDMetrics::Stopwatch.new
    stopwatch.start
  end

  on(:phase_ended) do |phase_name, rep|
    stopwatch = stopwatches[[phase_name, rep]]
    stopwatch.stop

    @phases_summary.observe(stopwatch.duration, name: phase_name)
  end

  on(:phase_yielded) do |phase_name, rep|
    stopwatch = stopwatches[[phase_name, rep]]
    stopwatch.stop
  end

  on(:phase_resumed) do |phase_name, rep|
    # It probably looks weird that a phase can be resumed even though it was not suspended earlier. This can happen when compilation is suspended, where you’d get the sequence started -> suspended -> started -> resumed.
    stopwatch = stopwatches[[phase_name, rep]]
    stopwatch.start unless stopwatch.running?
  end

  on(:phase_aborted) do |phase_name, rep|
    stopwatch = stopwatches[[phase_name, rep]]
    stopwatch.stop if stopwatch.running?

    @phases_summary.observe(stopwatch.duration, name: phase_name)
  end
end
table_for_summary(name, summary) click to toggle source
# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 107
def table_for_summary(name, summary)
  headers = [name.to_s, 'count', 'min', '.50', '.90', '.95', 'max', 'tot']

  rows = summary.map do |label, stats|
    name = label.fetch(:name)

    count = stats.count
    min   = stats.min
    p50   = stats.quantile(0.50)
    p90   = stats.quantile(0.90)
    p95   = stats.quantile(0.95)
    tot   = stats.sum
    max   = stats.max

    [name, count.to_s] + [min, p50, p90, p95, max, tot].map { |r| "#{format('%4.2f', r)}s" }
  end

  [headers] + rows
end
table_for_summary_durations(name, summary) click to toggle source
# File lib/nanoc/cli/compile_listeners/timing_recorder.rb, line 127
def table_for_summary_durations(name, summary)
  headers = [name.to_s, 'tot']

  rows = summary.map do |label, stats|
    name = label.fetch(:name)
    [name, "#{format('%4.2f', stats.sum)}s"]
  end

  [headers] + rows
end