BootProfiler

boot_profiler.rb

# Copyright (c) 2025 Artūrs Mekšs

# MIT License

# Permission is hereby granted, free of charge, to any person obtaining
# a copy of this software and associated documentation files (the
# "Software"), to deal in the Software without restriction, including
# without limitation the rights to use, copy, modify, merge, publish,
# distribute, sublicense, and/or sell copies of the Software, and to
# permit persons to whom the Software is furnished to do so, subject to
# the following conditions:

# The above copyright notice and this permission notice shall be
# included in all copies or substantial portions of the Software.

# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
# EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
# MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
# NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
# LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
# OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
# WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.

require "logger"
require "benchmark"

class BootProfiler
  # No-op profiler
  class << Noop = Object.new
    def rails_app_hook(_)
    end

    def track_require(_)
      yield
    end

    def finalize_and_report
    end
  end

  PREFIX = "[Boot-Profiling]"
  SLOW_REQUIRE_THRESHOLD = 0.1
  SLOW_REQUIRE_COUNT = 15
  APP_REQURES_KEY = :app
  GEM_REQURES_KEY = :gem

  def initialize
    @time_tracker = {
      begin: current_time,
      requires: {APP_REQURES_KEY => {}, GEM_REQURES_KEY => {}}
    }
    info("#{PREFIX} start")
  end

  def track_require(file_name)
    result = nil

    time = Benchmark.realtime do
      result = yield
    end

    if time > SLOW_REQUIRE_THRESHOLD
      source = file_name.start_with?(Dir.pwd) ? APP_REQURES_KEY : GEM_REQURES_KEY
      time_tracker[:requires][source][file_name] = time
    end

    result
  end

  def rails_app_hook(config)
    config.before_configuration do
      time_tracker[:begin_configuration] = current_time
    end

    config.before_initialize do
      time_tracker[:begin_initialize] = current_time
    end

    config.after_initialize do
      time_tracker[:end_initialize] = current_time
    end
    nil
  rescue => err
    handle(err)
  end

  def finalize_and_report
    time_tracker[:end] = current_time

    report
    nil
  rescue => err
    handle(err)
  end

  private

  attr_accessor :time_tracker

  def report
    payload = {
      load: duration_between(:begin, :begin_configuration),
      configuration: duration_between(:begin_configuration, :begin_initialize),
      initializers: duration_between(:begin_initialize, :end_initialize),
      server_boot: duration_between(:end_initialize, :end),
      total: duration_between(:begin, :end),
      slow_gem_requires: requires_to_arr(time_tracker[:requires][GEM_REQURES_KEY]),
      slow_app_requires: requires_to_arr(time_tracker[:requires][APP_REQURES_KEY])
    }.compact_blank

    info({
      message: "#{PREFIX} finished booting in #{payload[:total].round(2)}s",
      payload: payload
    }.to_json)
  end

  def requires_to_arr(tracked_requires, count: SLOW_REQUIRE_COUNT)
    tracked_requires.sort_by { |k, v| v }.reverse[0...count].map { |k, v| "#{v.round(2)} - #{k}" }
  end

  def current_time
    Time.now.utc
  end

  def duration_between(from, to)
    fetch(to) - fetch(from)
  end

  def fetch(key)
    time_tracker.fetch(key, 0)
  end

  def info(msg)
    logger.info(msg)
  rescue => err
    handle(err)
  end

  def logger
    @logger ||= ::Logger.new($stdout).tap do |l|
      l.formatter = ->(_level, _ts, _pname, msg) { "#{msg}\n" }
    end
  end

  def handle(err)
    logger.error("#{PREFIX} error - #{err}")
  end
end

# Expose profiler globally
BOOT_PROFILER = (ENV["ENABLE_BOOT_PROFILER"].to_s == "1") ? BootProfiler.new : BootProfiler::Noop

# Monkey-patching Kernel#require to track require times
def require(file_name)
  BOOT_PROFILER.track_require(file_name) { super }
end

rails_boot_profiling_2025.pdf