Rails Vernier Profiler: Ruby 3.3 Sampling Profiler voor Productie-Flamegraphs en Trage Requests

Een fintech-klant belde me woensdag omdat hun /dashboard-endpoint in zes maanden was afgedwaald van een gezonde P95 van 180ms naar een suffe 1,4s en niemand kon uitleggen waarom. Ze hadden New Relic, ze hadden rack-mini-profiler op staging, ze hadden een Datadog APM-trace die zijn schouders ophaalde en “Ruby” zei. Wat ze niet hadden was enig beeld van wat de Ruby VM daadwerkelijk aan het doen was binnen die 1,4 seconden. Ik vroeg ze om één gem toe te voegen — vernier — één productie-request vast te leggen met Vernier.trace, de JSON in de Firefox Profiler UI te droppen, en binnen vier minuten staarden we naar een flamegraph die liet zien dat 62% van de wall time in een geneste each-block zat die Object#respond_to? aanriep op 40.000 hashes. Twee-regel fix. Rails Vernier profiler maakte van een onzichtbare vertraging een voor de hand liggende bug.

Na negentien jaar Rails heb ik elke profiler gebruikt die een hype-cyclus overleefde: ruby-prof, perftools.rb, stackprof, rblineprof, memory_profiler, rack-mini-profiler. Sinds Ruby 3.3 uit is is er een nieuwe standaard en ik heb al mijn klanten-apps er inmiddels naartoe gemigreerd. Rails Vernier profiler is een sampling profiler geschreven voor de post-3.3 Ruby VM, hij begrijpt YJIT, hij vangt GVL- en GC-events native, en hij produceert flamegraphs die je daadwerkelijk leest in plaats van naar tuurt. Deze post is hoe ik hem installeer, hoe ik productie-requests vastleg zonder het proces op te blazen, en hoe ik de output lees.

Wat Rails Vernier Profiler Precies Is

Vernier is een Ruby sampling profiler van John Hawthorn (van Shopify) die als gem wordt uitgeleverd en Ruby 3.2.1+ vereist voor basisgebruik, waarbij het echte werk — echte stack sampling via de nieuwe rb_profile_frames-hooks — landt in Ruby 3.3. In tegenstelling tot stackprof, die gebouwd is voor de pre-YJIT Ruby VM en in de war raakt van JIT-gecompileerde frames, kent Rails Vernier profiler YJIT, ZJIT, native extensies, thread scheduling en GVL-contentie. In tegenstelling tot ruby-prof instrumenteert hij niet elke method-call, dus zijn overhead is laag genoeg om in productie te draaien op echt verkeer.

Praktisch gezien doet Vernier drie dingen die stackprof niet kan:

Hij vangt meerdere threads. Een Puma-worker die één request afhandelt terwijl een andere thread een ActionCable-verbinding draait, is een veelvoorkomend patroon, en stackprof ziet alleen de aanroepende thread. Vernier registreert elke Ruby-thread en elke native thread, dus je kunt GC-threads, Puma-reactor-threads en background-threads op dezelfde tijdlijn zien.

Hij vangt GVL-events. Wanneer een thread wacht om de Global VM Lock te bemachtigen — meestal omdat een native extensie blokkeert, of omdat een andere thread de lock vasthoudt tijdens een lang blok — registreert Vernier de wachttijd als een aparte gebeurtenis. Als je trage request eigenlijk 300ms geblokkeerd zit op de GVL omdat een background job hem inpikt, laat Vernier dit direct zien. Stackprof kan dat niet.

Hij vangt GC- en allocatie-events. Elke major GC, elke minor GC, elke compaction pause verschijnt als een marker op de tijdlijn, dus je kunt zien of je trage request samenviel met een 400ms GC-compaction of dat de app echt werk aan het doen was. Dit is belangrijker in productie dan in development omdat productie-heapgroottes anders zijn.

Het outputformaat is compatibel met de Firefox Profiler, dezelfde UI waar Mozilla’s C++-engineers naar staren wanneer ze Firefox zelf profileren. Hij is werkelijk goed — zoombaar, filterbaar, thread-aware, met een flamegraph-weergave en een call-tree-weergave en een marker-chart. Je upload de JSON op profiler.firefox.com en het draait volledig in je browser; niets wordt naar een server geüpload.

Rails Vernier Profiler Installeren

Voeg de gem toe aan je Gemfile. Ik houd hem in de default group omdat ik hem soms in productie wil hebben, maar als je voorzichtig bent kun je hem achter een group zetten en handmatig requiren wanneer je hem nodig hebt.

# Gemfile
gem "vernier", "~> 1.5"

Dan bundle install. Dat is de hele setup. Vernier is een pure gem — geen Rack middleware om te mounten, geen initializer om te schrijven, geen configuratiebestand. Je roept hem aan vanuit Ruby wanneer je een trace wilt.

Verifieer de installatie:

bin/rails runner 'Vernier.trace(out: "/tmp/warmup.vernier.json") { 100.times { "x" * 1000 } }'

Je zou een JSON-bestand in /tmp moeten krijgen. Sleep het naar profiler.firefox.com en je zou een flamegraph moeten zien. Als de JSON onder een paar kilobytes is en de flamegraph leeg is, staat je Ruby waarschijnlijk onder 3.3 en sampelt Vernier geen frames — upgrade Ruby voordat je verder gaat. Alles rond Rails Vernier profiler gaat uit van Ruby 3.3+.

Een Rails-Controller-Actie Profileren

Het eenvoudigste nuttige is om één controller-actie te omhullen voor een enkele request. Ik doe dit door een around-action toe te voegen die alleen actief wordt voor een specifieke query-parameter, zodat je on-demand een trace kunt triggeren zonder te redeployen.

class ApplicationController < ActionController::Base
  around_action :profile_with_vernier, if: -> { params[:vernier].present? && trusted_admin? }

  private

  def profile_with_vernier
    require "vernier"
    path = Rails.root.join("tmp", "vernier-#{Time.now.to_i}-#{SecureRandom.hex(4)}.json")
    Vernier.trace(out: path.to_s) do
      yield
    end
    response.headers["X-Vernier-Path"] = path.to_s
  end

  def trusted_admin?
    Current.user&.admin? && request.remote_ip.in?(TRUSTED_ADMIN_IPS)
  end
end

Bezoek een pagina met ?vernier=1 terwijl je als admin bent ingelogd, en de response-headers vertellen je waar de trace-JSON op de server terecht is gekomen. scp hem lokaal, sleep in de Firefox Profiler, klaar. Twee dingen zijn belangrijk bij dit patroon. Ten eerste de trusted_admin?-guard — laat nooit een willekeurige client een Vernier-trace triggeren, want een request profileren is niet gratis en iemand zou je kunnen DoS’en door ?vernier=1 in een loop op te vragen. Ten tweede staat het trace-pad in tmp/ zodat het je log-volume niet vervuilt; voeg een cron of een scheduled job toe om oude traces op te schonen.

Als je liever geen profilecode in de codebase strooit, levert Vernier een Rack-middleware die je vanuit een initializer kunt mounten die alleen in development leeft of achter een feature flag:

# config/initializers/vernier.rb
if ENV["VERNIER_MIDDLEWARE"] == "1"
  require "vernier/middleware"
  Rails.application.config.middleware.use Vernier::Middleware
end

Boot de app met VERNIER_MIDDLEWARE=1 bin/rails s, bezoek een request met ?vernier=true, en de middleware schrijft een trace en retourneert de profiler-URL als een response-header. Ik prefereer de around-action-aanpak voor productie omdat hij samengaat met autorisatie; middleware is prima voor staging.

Een Background Job Profileren

De helft van het trage-request-werk in een volwassen Rails-app zit niet in controllers, maar in Sidekiq- of Solid Queue-jobs die na 15 minuten timeouten en niemand weet waarom. Vernier is hier perfect voor omdat je al de job-klasse hebt, je perform voorwaardelijk kunt omhullen, en je log-context hebt om de trace terug te correleren naar een Sidekiq job-ID.

class ReportGenerationJob < ApplicationJob
  queue_as :reports

  around_perform do |job, block|
    if ENV["VERNIER_JOBS"] == "1" || job.arguments.first == "profile-me"
      require "vernier"
      path = Rails.root.join("tmp", "vernier-job-#{job.job_id}.json")
      Vernier.trace(out: path.to_s, &block)
      Rails.logger.info(vernier_trace: path.to_s, job_id: job.job_id)
    else
      block.call
    end
  end

  def perform(scope)
    Report.slow_query(scope).each { |row| row.crunch! }
  end
end

Enqueue met een synthetisch argument, wacht tot de job klaar is, grep het log op vernier_trace, scp de JSON van de worker af, upload naar de profiler. Op het systeem van mijn klant vond deze workflow een job die 47% van zijn tijd in ActiveRecord::Base#reload doorbracht omdat iemand record.reload binnen een .each in een helper had gezet — een fout die stackprof ook zou tonen, maar Vernier’s marker-chart liet ook de begeleidende 12 minor GC’s zien, wat hen ervan overtuigde om het meteen op te lossen.

Continue Profiling in Productie

Voor productie gebruik ik twee patronen afhankelijk van het risicoprofiel. Beide zijn veilig mits goed geconfigureerd en beide geven je het vermogen om “waar heeft de app dinsdag om 3 uur zijn tijd aan besteed” te beantwoorden zonder te redeployen.

Het eerste patroon is triggered on-demand profiling — de around-action hierboven, achter admin-auth. Dit is wat ik gebruik op kleinere apps waar ik geen continue dekking nodig heb.

Het tweede patroon is timed background sampling — een thread die Vernier elke N minuten start en stopt gedurende een kort venster. Dit is wat ik gebruik op grotere apps waar problemen intermitterend reproduceren.

# config/initializers/vernier_background_sampler.rb
if Rails.env.production? && ENV["VERNIER_SAMPLER"] == "1"
  Thread.new do
    Thread.current.name = "vernier-sampler"
    loop do
      begin
        require "vernier"
        window = 15
        path = Rails.root.join("tmp", "vernier-bg-#{Time.now.to_i}.json")
        collector = Vernier::Collector.new(:wall, out: path.to_s)
        collector.start
        sleep window
        collector.stop
        Rails.logger.info(vernier_bg_trace: path.to_s, window_sec: window)
        upload_to_s3(path)
        File.delete(path)
      rescue => e
        Rails.logger.error(vernier_sampler_error: e.message)
      ensure
        sleep 5.minutes.to_i
      end
    end
  end
end

Elke vijf minuten sampelt hij vijftien seconden, upload de trace naar S3, verwijdert het lokale bestand. De overhead van een wall-clock sample is ongeveer 1-2% en alleen tijdens het sample-venster, dus je betaalt ruwweg 0,1% totaal. Wanneer een klant klaagt dat iets traag was om 14:37 UTC, heb je binnen enkele minuten van die tijdstempel al een trace in S3 staan.

Twee productie-kanttekeningen. Ten eerste: draai Vernier op één worker per host tegelijk; een hele fleet die tegelijk profileert brandt CPU op. Ik gate de sampler meestal op Process.pid.even? of op een specifiek hostname-patroon zodat slechts een subset van workers profileert. Ten tweede: wall-mode legt wall-clock-tijd vast (het beste voor het vinden van geblokkeerde IO); retained-mode legt allocaties vast die over GC heen overleven (het beste voor geheugengroei). Wall is de juiste default; schakel over naar retained wanneer je een lek vermoedt.

Een Vernier-Flamegraph Lezen

De Firefox Profiler UI heeft drie panelen die ik in volgorde gebruik. De tijdlijn bovenaan toont CPU-gebruik, GVL-activiteit en GC-markers over de trace. De flamegraph in het midden toont een stack-sample-verdeling: breder = meer samples daar besteed. De call tree aan de rechterkant laat je sorteren op totale tijd of eigen tijd.

De heuristiek die ik klanten leer is een two-pass read.

Eerste pass — top van de flamegraph. Zoek naar de breedste blokken aan de top van de stack. Dat zijn de leaf-functies waar samples het vaakst landen. Als je ActiveRecord::Base#reload ziet die 40% van de breedte inneemt, gaat je tijd daar naartoe. Als je #[] van een hash 25% ziet innemen, kijkt iemand veel hash-keys op — waarschijnlijk een N+1 in vermomming, of een slecht gememoiseerde helper.

Tweede pass — GVL- en GC-markers. Kijk in de tijdlijn naar rode of oranje balken die GVL-waits en GC-pauzes aangeven. Als de GC-balk 30% van de tijdlijn is, is je probleem allocatie-druk, geen trage code. Los het op door de breedste allocatie-blokken in de flamegraph te vinden (Vernier tagt allocatie-events in de retained-mode) en ze te verminderen — vaak een .to_a binnen een loop, een .dup die een referentie zou moeten zijn, of een String#+ die een String#<< zou moeten zijn.

De fout die beginners maken met flamegraphs is de bodem lezen (de breedste blokken onderaan, meestal Rack::Server#call of ActionDispatch::Executor#call) als het “trage” ding. Dat is het niet — de basis van de flamegraph is gewoon het entry-point, en elke request gaat er doorheen. De interessante informatie zit aan de top, waar de samples daadwerkelijk landen.

Vernier vs Stackprof vs Rack Mini Profiler

Deze drie tools klinken gelijk en zijn dat niet. Ik gebruik alle drie voor verschillende taken, maar de overlap is kleiner dan nieuwkomers denken.

Rack mini profiler is een Rack-middleware die je een per-request-breakdown toont van SQL-queries, view-rendering-tijd en totale request-tijd als een toolbar in de browser. Het is een workflow-tool voor het vinden van “welk endpoint is traag” en “hoeveel SQL-queries heeft deze pagina uitgevoerd”. Hij samplet geen Ruby-stackframes — hij haakt in op Rails’ notifications. Het beste voor development en staging. Ik heb hem uitgebreid behandeld in Rack Mini Profiler.

Stackprof is een sampling profiler van Aman Gupta die dateert van vóór YJIT. Hij is stabiel, klein en nog steeds prima voor pre-3.3 Ruby. Zijn outputformaat is proprietary en zijn viewer is stackprof --text, wat prima is voor command-line-lezen maar minder bruikbaar dan een flamegraph. Hij ziet geen GVL, ziet meerdere threads niet goed, en begrijpt geen YJIT-frames.

Rails Vernier profiler is de opvolger: multi-threaded, YJIT-aware, GVL-aware, GC-aware, met een goede UI. Gebruik hem voor alles op Ruby 3.3+. Gebruik stackprof alleen als je vastzit op oudere Ruby.

De ruwe beslisboom: “Ik wil weten waarom deze pagina nu traag is” → rack-mini-profiler. “Ik wil weten waar mijn proces tijd aan besteedt over een hele request of job” → Vernier. “Ik wil continue productie-profiling met een goede UI” → Vernier met een background sampler.

Veelgemaakte Fouten Die Ik Ben Tegengekomen

Drie fouten die ik heb gemaakt of klanten heb zien maken met Rails Vernier profiler in het afgelopen jaar.

Een enkele request sampelen die niet traag is. Een Vernier-trace van één seconde op een snelle request toont zeer weinig samples en ziet er leeg uit. Trigger de trace op een request waarvan je al weet dat hij traag is, of gebruik de background sampler om langere vensters vast te leggen.

Vergeten van Ruby 3.3+. Op Ruby 3.2 krijg je gedeeltelijke data — stack-frames worden vastgelegd maar GVL- en native-thread-informatie niet, en de flamegraph ziet er bloedarmoedig uit. Als je productie nog op 3.2 draait, upgrade eerst; Vernier is een van de beste redenen om te verhuizen.

Profileren met tests. Vernier werkt binnen RSpec, maar de boot-fase domineert de flamegraph als je een snelle test profileert. Omhul alleen de code onder test, niet de hele run. Voor een full-suite-profiel gebruik Vernier.trace(mode: :wall, out: "/tmp/spec.json") { RSpec::Core::Runner.run(...) } en kijk naar wat er gebeurt na de boot.

FAQ

Werkt Vernier met YJIT en Ruby 3.3?

Ja — Vernier is ontworpen voor de Ruby 3.3 profiler-API en begrijpt YJIT-gecompileerde frames. Dat is een van zijn belangrijkste bestaansredenen. Oudere profilers zoals stackprof zien JIT-frames als onbekend of missen ze. Rails Vernier profiler toont ze correct gelabeld, wat belangrijk is als je YJIT in productie hebt aanstaan.

Is het veilig om Vernier in productie te draaien?

Ja, met twee kanttekeningen. Sampling-overhead is 1-3% tijdens het trace-venster, wat prima is voor een capture van enkele seconden maar oploopt als je hem continu draait op elke worker. Gate de sampler op één worker per host, gebruik korte vensters (15-30 seconden) en houd het sample-interval op de default (1ms wall). Zet Vernier niet globaal aan op elke request — profileer specifieke trage requests of neem getimede background-samples.

Hoe profileer ik geheugenallocaties met Vernier?

Gebruik Vernier.trace(mode: :retained, out: "path.json") { ... } om allocaties te sampelen die GC overleven. Dit is wat je wilt voor het detecteren van leaks en hete allocatiesites. mode: :allocations samplet elke allocatie ongeacht retentie en is duurder; gebruik hem in development wanneer je elke laatste allocatie nodig hebt.

Waar bekijk ik Vernier-output?

De gegenereerde JSON is compatibel met de Firefox Profiler op profiler.firefox.com. Alles draait client-side in je browser; niets wordt naar Mozilla geüpload. Voor CI- of headless-omgevingen is er ook vernier view dat een HTML-bestand schrijft dat je lokaal kunt serveren.

Zit je vast met de vraag waar je Rails-proces zijn tijd aan besteedt? TTB Software doet hands-on Rails performance werk — Vernier, YJIT, Postgres, background jobs. Wij doen dit al negentien jaar.