CODEWITHSUNDEEP
ruby-on-railsrubyruby-on-rails-6puma
Cyril Duchon-Doris
Cyril Duchon-Doris

Reputation: 13999

How can I log the time taken to start a rails app

How can I log the start duration taken by a rails application until it is ready to serve requests ?

A naive approach by adding puts "Rails app booted in #{(boot_start - Time.now)} seconds" in boot.rb` does not work as intended.

# config/boot.rb
boot_start = Time.now

require "bundler/setup"
require "bootsnap/setup" if ENV["RAILS_ENV"] == "development"

puts "Rails app booted in #{(boot_start - Time.now)} seconds"

What I need is

Note that the naive approach I refered to above prints the duration BEFORE the web server actually starts :

app_1       | Database 'XXX_staging' already exists
app_1       | Rails app booted in -1.2772e-05 seconds # Not only it appears before the server is ready
app_1       | Rails app booted in -1.01e-05 seconds   # But is also duplicated for some reason
app_1       | => Booting Puma
app_1       | => Rails 6.1.3.2 application starting in staging
app_1       | => Run `bin/rails server --help` for more startup options
app_1       | [12] Puma starting in cluster mode...
app_1       | [12] * Puma version: 5.3.1 (ruby 3.0.1-p64) ("Sweetnighter")
app_1       | [12] *  Min threads: 5
app_1       | [12] *  Max threads: 5
app_1       | [12] *  Environment: staging
app_1       | [12] *   Master PID: 12
app_1       | [12] *      Workers: 2
app_1       | [12] *     Restarts: (✔) hot (✖) phased
app_1       | [12] * Preloading application
app_1       | [12] * Listening on http://0.0.0.0:3000

I understand the web server is starting asynchronously and the way to measure will be coupled to the actual web server used to run the application (puma in this case) but an example of how this could be achieved using any webserver could be useful.

Upvotes: 2

Views: 1470

Answers (1)

Léonard Henriquez
Léonard Henriquez

Reputation: 738

You can add the following code to your profile/boot.rb and then run time bundle exec rake environment | sort:

# config/boot.rb

require 'benchmark'

def require(file_name)
  result = nil

  time = Benchmark.realtime do
    result = super
  end

  if time > 0.1
    puts "#{time} #{file_name}"
  end

  result
end

It should give you an output similar to this one:

0.16465099999913946 ruby_parser
0.1686829999962356 sprockets/railtie
0.1764029999903869 rails
0.2461370000091847 pg_ext
0.24949699998251162 pg
0.26813800001400523 active_record/connection_adapters/postgresql_adapter
0.32413899997482076 mimemagic
0.3775960000057239 active_record/connection_adapters/postgis_adapter
0.4651059999887366 rails/all
0.549659000011161 rubocop
7.2341489999962505 /Users/leo/code/Flatlooker/config/environment.rb
bundle exec rake environment  7,05s user 2,82s system 67% cpu 14,615 total
sort  0,00s user 0,00s system 0% cpu 14,615 total

Another great option is the gem Bumbler

Credit to https://mildlyinternet.com/code/profiling-rails-boot-time.html

Upvotes: 2

Related Questions