How to debug a Rails asset precompile which is unbearably slow

Question

I'm working on a Rails 3.2 project and the assets have increased a fair bit in recent months although I wouldn't consider the project to be large. The assets consist of JS (no coffee-script), and SASS files; we've quite a few images but they've been there more less since the early days so I don't think they are a substantial factor. We may have about a dozen libs and most are small, the largest is Jquery UI JS. Deployment is done via Capistrano and it started to become apparent that deploying to staging was significantly faster than to production. To illustrate whilst avoiding factors about different servers and network effects I simply ran the following three commands in sequence on my laptop as follows:

$ time RAILS_ENV=production bundle exec rake assets:precompile ^Crake aborted! [Note I aborted this run as I felt it was getting stupidly long...] real    52m33.656s user    50m48.993s sys 1m42.165s  $ time RAILS_ENV=staging bundle exec rake assets:precompile real    0m41.685s user    0m38.808s sys 0m2.803s  $ time RAILS_ENV=development bundle exec rake assets:precompile real    0m12.157s user    0m10.567s sys 0m1.531s 

So I'm left scratching my head. Why are there such massive differences between the various environments? I can understand the gap between development and staging, but our configs for staging and production are identical. (I should point out that the production compile will complete after about 2hrs!)

Whilst the end result is getting my precompile to be faster, I want to accomplish this by understanding where all the time is going and why there are such big differences between the Rails environments. I've seen other posts about using different compressors and such like but I can't find any information about how to debug these rake tasks to work out where the time is being spent and identify which settings may be causing such dramatic differences.

I don't know what additional information people may need so will update if and when comments ask. TIA

Update: additional information supplied below

config/environments/production.rb and config/environments/staging.rb (they're exactly the same):

MyRailsApp::Application.configure do   # Code is not reloaded between requests   config.cache_classes = true    # Full error reports are disabled and caching is turned on   config.consider_all_requests_local       = false   config.action_controller.perform_caching = true    # Disable Rails's static asset server (Apache or nginx will already do this)   config.serve_static_assets = true   config.static_cache_control = "public, max-age=31536000"   config.action_controller.asset_host = "//#{MyRailsApp::CONFIG[:cdn]}"    # Compress JavaScripts and CSS   config.assets.compress = true    # Don't fallback to assets pipeline if a precompiled asset is missed   config.assets.compile = false    # Generate digests for assets URLs   config.assets.digest = true    # Enable locale fallbacks for I18n (makes lookups for any locale fall back to   # the I18n.default_locale when a translation can not be found)   config.i18n.fallbacks = true    # Send deprecation notices to registered listeners   config.active_support.deprecation = :notify end 

The base config/application.rb is:

require File.expand_path('../boot', __FILE__)  require 'rails/all'  if defined?(Bundler)   # If you precompile assets before deploying to production, use this line   Bundler.require(*Rails.groups(:assets => %w(development test)))   # If you want your assets lazily compiled in production, use this line   # Bundler.require(:default, :assets, Rails.env) end module MyRailsApp   CONFIG = YAML.load_file(File.join(File.dirname(__FILE__), 'config.yml'))[Rails.env]    class Application < Rails::Application      # Custom directories with classes and modules you want to be autoloadable.     config.autoload_paths += %W(#{config.root}/lib)     config.autoload_paths += %W(#{config.root}/app/workers)      # Configure the default encoding used in templates for Ruby 1.9.     config.encoding = "utf-8"      # Configure sensitive parameters which will be filtered from the log file.     config.filter_parameters += [:password]      # Enable the asset pipeline     config.assets.enabled = true      # Stop precompile from looking for the database     config.assets.initialize_on_precompile = false      # Version of your assets, change this if you want to expire all your assets     config.assets.version = '1.0'      # Fix fonts in assets pipeline     # http://stackoverflow.com/questions/6510006/add-a-new-asset-path-in-rails-3-1     config.assets.paths << Rails.root.join('app','assets','fonts')      config.middleware.insert 0, 'Rack::Cache', {       :verbose     => true,       :metastore   => URI.encode("file:#{Rails.root}/tmp/dragonfly/cache/meta"),       :entitystore => URI.encode("file:#{Rails.root}/tmp/dragonfly/cache/body")     } # unless Rails.env.production?  ## uncomment this 'unless' in Rails 3.1,                                       ## because it already inserts Rack::Cache in production      config.middleware.insert_after 'Rack::Cache', 'Dragonfly::Middleware', :images      config.action_mailer.default_url_options = { :host => CONFIG[:email][:host] }     config.action_mailer.asset_host = 'http://' + CONFIG[:email][:host]   end end 

Gem file:

source 'http://rubygems.org'  gem 'rails', '3.2.13'    gem 'mysql2' gem 'dragonfly', '>= 0.9.14' gem 'rack-cache', :require => 'rack/cache' gem 'will_paginate' gem 'dynamic_form' gem 'amazon_product' # for looking up Amazon ASIN codes of books gem 'geoip' gem 'mobile-fu' gem 'airbrake' gem 'newrelic_rpm' gem 'bartt-ssl_requirement', '~>1.4.0', :require => 'ssl_requirement' gem 'dalli' # memcache for api_cache gem 'api_cache' gem 'daemons' gem 'delayed_job_active_record' gem 'attr_encrypted' gem 'rest-client' gem 'json', '>= 1.7.7' gem 'carrierwave' # simplify file uploads gem 'net-scp'  # Gems used only for assets and not required # in production environments by default. group :assets do   gem 'therubyracer'   gem 'sass-rails',   '~> 3.2.3'   gem 'compass', '~> 0.12.alpha'   gem 'uglifier', '>= 1.0.3'   gem 'jquery-fileupload-rails' end  gem 'jquery-rails' gem 'api_bee', :git => 'git://github.com/ismasan/ApiBee.git', :ref => '3cff959fea5963cf46b3d5730d68927cebcc59a8' gem 'httparty', '>= 0.10.2' gem 'twitter'  # Auth providers gem 'omniauth-facebook' gem 'omniauth-twitter' gem 'omniauth-google-oauth2' gem 'omniauth-identity' gem 'omniauth-readmill' gem 'bcrypt-ruby', "~> 3.0.0" # required for omniauth-identity gem 'mail_view'  # To use ActiveModel has_secure_password # gem 'bcrypt-ruby', '~> 3.0.0'  # Deploy with Capistrano group :development do   gem 'capistrano'   gem 'capistrano-ext'   gem 'capistrano_colors'   gem 'rvm-capistrano'    # requirement for Hoof, Linux equivalent of Pow   gem 'unicorn' end  group :test, :development do     gem 'rspec-rails'   gem 'pry'   gem 'pry-rails' end  group :test do   gem 'factory_girl_rails'   gem 'capybara'   gem 'cucumber-rails'   gem 'database_cleaner'   gem 'launchy'   gem 'ruby-debug19'   # Pretty printed test output   gem 'shoulda-matchers'   gem 'simplecov', :require => false   gem 'email_spec'   gem 'show_me_the_cookies'   gem 'vcr'   gem 'webmock', '1.6' end 

Answer 1

This may not entirely answer your question, but I believe it is a decent enough start. As you'll see, the precise answer will depend on the individual application, gem versions and so on.

So. For asset-related work, as you know, Rails uses a library called Sprockets, which in newer versions of Rails is, I believe, hooked into Rails as a Railtie. It initializes a Sprockets "environment" that can do things like look at your asset manifest, load those files, compress them, give the compiled assets sensible names, etc.

By default, that Sprockets::Environment logs its activity to STDERR with a log level of FATAL, which isn't very useful in these situations. Fortunately, the Sprockets::Environment (as of 2.2.2) has a writeable logger attribute that you can patch in via Rails, using an initializer.

---

So, here's what I suggest, to start:

In config/initializers, create a file, something like asset_logging.rb. In it, put:

Rails.application.config.assets.logger = Logger.new($stdout) 

This overwrites the default logger with one that will spit more information out to STDOUT. Once you've got this set up, then run your asset pre-compilation task:

rake RAILS_ENV=production assets:precompile 

And you should see slightly more interesting output, such as:

... Compiled jquery.ui.core.js  (0ms)  (pid 66524) Compiled jquery.ui.widget.js  (0ms)  (pid 66524) Compiled jquery.ui.accordion.js  (10ms)  (pid 66524) ... 

---

But, in the end, the final answer will depend on:

• how "deep" you want to go with logging this asset stuff
• what specific version of Rails, Sprockets, etc. you're using
• and what you find along the way

As you've already learned, log spelunking at the Rake task level, or even at the Rails level, doesn't give much information. And even making Sprockets itself verbose (see above) doesn't tell you too terribly much.

If you wanted to go deeper than Sprockets, you can probably monkey patch the various engines and processors that Sprockets dutifully chains together to make the asset pipeline work. For example, you could look into the logging capabilities of these components:

• Sass::Engine (converts SASS to CSS)
• Uglifier (JavaScript compressor wrapper)
• ExecJS (runs JavaScript in Ruby; a dependency of both Sprockets and Uglifier)
• therubyracer (V8 embedded in Ruby; used by ExecJS)
• etc.

But I will leave all that as "an exercise for the reader." If there's a silver bullet, I'd certainly like to know about it!

Answer 2

there is a bunch of possible causes to this issue.

for a possible cause, i would like to know how the time of compiling the assets increased in the several environments for your last deploys. this might indicate if the problem is just on the environments or within the asset compilation itself. you could use git bisect for that. i usually have my apps deployed to staging via a jenkins or another ci system so that i can see any variations in deploy time and when they were introduced.

it might boil down to extensive use of resources CPU, MEMORY (any swap?), IO. if you compile the assets on the production systems they might be busy serving your applications request. go to your system, do a top for resources, maybe there are too many file handles at the same time (lsof is good for that).

another thing might be that you load or cache some data for your application. databases are usually much larger in staging and production environments then they are on dev boxes. you could just put some Rails.logger calls in your initializers or whaterver.