The Always-On Profiler

The Always-On Profiler: the mini-profiler heresy is that profiling belongs in PRODUCTION, on EVERY request, visible to the people who wrote the slow code - not in a lab you visit twice a year. Every plan gets a badge line; plans over their latency budget get named, with the top offender attached; and the profiler measures its own overhead, because always-on is only defensible when it's near-free.

source on github

a real captured run

THE ALWAYS-ON PROFILER (a badge on every plan, budgets with teeth)

  [prof] completed     69ms  3 tasks  top: rank (30ms)  within budget
  [prof] completed    144ms  3 tasks  top: summarize (97ms)  OVER BUDGET (120ms) <- fix summarize first
  [prof] completed      5ms  1 tasks  top: check (5ms)  within budget

  overhead audit: 4.18ms/plan without hooks, 3.43ms with - the
  profiler costs 752 microseconds per plan, which is the entire
  argument for leaving it on. the lab-visit model of profiling
  finds the regressions you already shipped; the badge model
  finds them in the PR preview, because the person who made
  summarize slow SAW the badge go red before they merged. three
  rules made mini-profiler work and they all transplant: always
  on (sampling is for whales; plans can afford everything),
  visible to the AUTHOR (not a grafana nobody opens), and
  budgets with a named offender - 'over budget, fix summarize
  first' is an assignment; a p95 chart is a vibe.

source

# frozen_string_literal: true

# The Always-On Profiler: the mini-profiler heresy is that profiling
# belongs in PRODUCTION, on EVERY request, visible to the people who
# wrote the slow code - not in a lab you visit twice a year. Every
# plan gets a badge line; plans over their latency budget get named,
# with the top offender attached; and the profiler measures its own
# overhead, because always-on is only defensible when it's near-free.
#
#   bundle exec ruby examples/always_on_profiler.rb
#
# Runs offline; three plans run, one blows its budget.

require class="s">"bundler/setup"
require class="s">"agentic"

Agentic.logger.level = class="y">:fatal

# The whole profiler: hooks in, one badge line out per plan
class AlwaysOn
  def initialize(budget_ms:)
    @budget_ms = budget_ms
    @timings = []
  end

  def hooks
    {
      after_task_success: ->(task_id:, task:, result:, duration:) {
        @timings << [task.description, duration * 1000]
      },
      plan_completed: ->(plan_id:, status:, execution_time:, tasks:, results:) {
        badge(plan_id, status, execution_time * 1000)
        @timings.clear
      }
    }
  end

  def badge(plan_id, status, total_ms)
    top = @timings.max_by(&class="y">:last)
    line = format(class="s">"[prof] %-10s %5.0fms  %d tasks  top: %s (%.0fms)",
      status, total_ms, @timings.size, top[0], top[1])
    if total_ms > @budget_ms
      puts class="s">"  #{line}  OVER BUDGET (#{@budget_ms}ms) <- fix #{top[0]} first"
    else
      puts class="s">"  #{line}  within budget"
    end
  end
end

def run_plan(name, workloads, hooks: {})
  orchestrator = Agentic:class="y">:PlanOrchestrator.new(concurrency_limit: 2, lifecycle_hooks: hooks)
  previous = nil
  workloads.each do |task_name, ms|
    task = Agentic:class="y">:Task.new(description: task_name, agent_spec: {class="s">"name" => task_name, class="s">"instructions" => class="s">"w"})
    orchestrator.add_task(task, previous ? [previous] : [], agent: ->(_t) {
      sleep(ms / 1000.0)
      class="y">:ok
    })
    previous = task
  end
  orchestrator.execute_plan
end

puts class="s">"THE ALWAYS-ON PROFILER (a badge on every plan, budgets with teeth)"
puts
profiler = AlwaysOn.new(budget_ms: 120)
run_plan(class="s">"morning digest", {class="s">"fetch" => 20, class="s">"rank" => 30, class="s">"render" => 15}, hooks: profiler.hooks)
run_plan(class="s">"weekly report", {class="s">"gather" => 25, class="s">"summarize" => 95, class="s">"publish" => 20}, hooks: profiler.hooks)
run_plan(class="s">"tiny ping", {class="s">"check" => 5}, hooks: profiler.hooks)
puts

# --- the overhead audit: always-on must be near-free -----------------------------
runs = 30
bare = ->(hooks) {
  t0 = Process.clock_gettime(Process:class="y">:CLOCK_MONOTONIC)
  runs.times { run_plan(class="s">"bench", {class="s">"a" => 1, class="s">"b" => 1}, hooks: hooks) }
  (Process.clock_gettime(Process:class="y">:CLOCK_MONOTONIC) - t0) / runs * 1000
}
silent = Class.new(AlwaysOn) {
  def badge(*)
  end
}.new(budget_ms: 999)
without = bare.call({})
with = bare.call(silent.hooks)

puts format(class="s">"  overhead audit: %.2fms/plan without hooks, %.2fms with - the", without, with)
puts format(class="s">"  profiler costs %.0f microseconds per plan, which is the entire", (with - without).abs * 1000)
puts class="s">"  argument for leaving it on. the lab-visit model of profiling"
puts class="s">"  finds the regressions you already shipped; the badge model"
puts class="s">"  finds them in the PR preview, because the person who made"
puts class="s">"  summarize slow SAW the badge go red before they merged. three"
puts class="s">"  rules made mini-profiler work and they all transplant: always"
puts class="s">"  on (sampling is for whales; plans can afford everything),"
puts class="s">"  visible to the AUTHOR (not a grafana nobody opens), and"
puts class="s">"  budgets with a named offender - 'over budget, fix summarize"
puts class="s">"  first' is an assignment; a p95 chart is a vibe."