[Rails] gained a lot of its focus and appeal because I didn’t try to please people who didn’t share my problems. Differentiating between production and development was a very real problem for me, so I solved it the best way I knew how. | ||
| --David Heinemeier Hansson | ||
Rails applications are preconfigured with three standard modes of operation: development, test, and production. These modes are basically execution environments and have a collection of associated settings that determine things such as which database to connect to, and whether or not the classes of your application are reloaded with each request. It is also simple to create your own custom environments if necessary.
The current environment is always specified in the environment variable RAILS_ENV, which names the desired mode of operation and corresponds to an environment definition file in the config/environment folder. Since the environment settings govern some of the most fundamental aspects of Rails, such as classloading, in order to really understand the Rails way you should really understand its environment settings.
In this chapter, we get familiar with how Rails starts up and handles requests, by examining scripts such as boot.rb and environments.rb and the settings that make up the three standard environment settings (modes). We also cover some of the basics of defining your own environments, and why you might choose to do so.
Whenever you start a process to handle requests with Rails (such as a Webrick server), one of the first things that happens is that config/environment.rb is loaded. For instance, take a look at the top of public/dispatch.rb:
require File.dirname(__FILE__) + "/../config/environment"
Other processes that need the whole Rails environment, such as the console and your tests, also require config/environment.rb, hence you’ll notice the require statement at the top files such as test/test_helper.rb.
Let’s go step by step through the settings provided in the default environment.rb file that you get when bootstrapping a Rails 1.2 application.
The first setting is only applicable to people deploying on shared hosting environments. It is commented out, since it should be unusual to need to set the Rails mode here:
# Uncomment below to force Rails into production mode when # you don't control web/app server and can't set it the proper way # ENV['RAILS_ENV'] ||= 'production'
A word of caution: If you were to set the RAILS_ENV environment variable to production here, or the constant variable RAILS_ENV for that matter, it would cause everything you did in Rails to run in production mode. For instance, your test suite would not work correctly, since test_helper.rb sets RAILS_ENV to test right before loading the environment.
Remember that at this point, the Rails framework hasn’t been loaded—in fact, the script has to find the framework and load it before anything else happens. This setting tells the script which version of Rails to load:
# Specifies gem version of Rails to use when vendor/rails is not present RAILS_GEM_VERSION = '1.2.3'
As you can see, at the time that I’m writing this chapter the latest released version of Rails (that I have installed as a gem, anyway) is 1.2.3. This setting is meaningless if you’re running edge, which is the community-accepted term meaning that you’re running a frozen snapshot of Rails out of the vendor/rails directory of your project. You can invoke the rake rails:freeze:edge command in your project to copy the latest repository version of Rails into vendor/rails.
The next lines of environment.rb are where the wheels really start turning, once config/boot.rb is loaded:
# Bootstrap the Rails environment, frameworks, and default configuration require File.join(File.dirname(__FILE__), 'boot')
Note that the boot script is generated as part of your Rails application, but it is not meant to be edited. I’ll briefly describe what it does, since it may help you troubleshoot a broken Rails installation.
First of all, the boot script ensures that the RAILS_ROOT environment variable is set: It holds the path to the root of the current Rails project. RAILS_ROOT is used all over the place in the Rails codebase for finding files, such as view templates. If it isn’t set already, the folder one level up is specified (remember that we’re currently in the config folder).
On non-Windows platforms, the useful standard Ruby library pathname is used to clean up the path string by removing consecutive slashes and useless dots:
unless RUBY_PLATFORM =~ /mswin32/ require 'pathname' root_path = Pathname.new(root_path).cleanpath(true).to_s end
Now the boot script has to figure out which version of Rails to use. The first thing it does is to check for the existence of vendor/rails in your project, which would mean that you’re running edge:
File.directory?("#{RAILS_ROOT}/vendor/rails")That is essentially the easiest case. Unless you’re not running edge, and I’d guess that most Rails developers do not, then the boot script has to do a little bit more work to find Rails as a RubyGem.
First, the boot script requires rubygems. You probably know about RubyGems already, since you had to install it in order to install Rails, by invoking gem install rails from the command line.
For reasons outside of the scope of this discussion, sometimes Rails is loaded with just the boot script. So the next thing the boot script does is read the config/environment.rb file as text (minus the commented lines) and parse out the RAILS_GEM_VERSION setting with a regexp.
Once the boot script determines which version of Rails to load, it requires the Rails gem. At this point, if the Rails version specified in your particular environment.rb file is out of synch with the versions available on your workstation, you’ll have a problem, indicated by an error message similar to the following one when you try to start a Rails server or console:
Cannot find gem for Rails =1.1.5: Install the missing gem with 'gem install -v=1.1.5 rails', or change environment.rb to define RAILS_GEM_VERSION with your desired version.
The boot script then requires the Rails script initializer.rb, which is responsible for configuration and will be used next by the environment script.
Finally, the boot script tells the initializer to set up default load paths (in other words, it constructs the classpath). The load path is assembled from the list of component frameworks that make up Rails and the folders of your Rails application that contain code. Remember that load paths in Ruby just specify where the require method should look for code when invoked. Until this point, the load path was only the current working directory.
The Rails code that specifies the load paths is pretty readable and well-commented, so I’ll copy it instead of explaining it. See Listing 1.1.
Example 1.1. Some of the Methods in railties/lib/initializer.rb
def default_frameworks
[ :active_record, :action_controller, :action_view,
:action_mailer, :action_web_service ]
end
def default_load_paths
paths = ["#{root_path}/test/mocks/#{environment}"]
# Add the app's controller directory
paths.concat(Dir["#{root_path}/app/controllers/"])
# Then components subdirectories.
paths.concat(Dir["#{root_path}/components/[_a-z]*"])
# Followed by the standard includes.
paths.concat %w(
app
app/models
app/controllers
app/helpers
app/services
app/apis
components
config
lib
vendor
).map { |dir| "#{root_path}/#{dir}" }.select { |dir|
File.directory?(dir) }
paths.concat Dir["#{root_path}/vendor/plugins/*/lib/"]
paths.concat builtin_directories
end
def builtin_directories
# Include builtins only in the development environment.
(environment == 'development') ?
Dir["#{RAILTIES_PATH}/builtin/*/"] : []
endNormally in Ruby, when you want to include code from another file in your application, you have to include a require statement. However, Rails enhances Ruby’s default behavior by establishing a simple convention that enables Rails to automatically load your code in most cases.
If you’ve used the Rails console at all, you’ve already seen this behavior in action: You never have to explicitly load anything!
This is how it works: If Rails encounters a class or module in your code that is not already defined, Rails uses the following convention to guess which files it should require to load that module or class:
If the class or module is not nested, insert an underscore between the constant’s names and require a file of this name. For example:
EstimationCalculator becomes require ‘estimation_calculator’
KittTurboBoost becomes require ‘kitt_turbo_boost’
If the class or module is nested, Rails inserts an underscore between each of the containing modules and requires a file in the corresponding set of subdirectories. For example:
MacGyver::SwissArmyKnife becomes require ‘mac_gyver/swiss_army_knife’
Some::ReallyRatherDeeply::NestedClassbecomesrequire 'some/really_rather_deeply/nested_class'and if not already loaded, Rails would expect to find it in a file callednested_class.rb, in a directory calledreally_rather_deeply, itself in the directorysomeof which can be found somewhere in Ruby’s load path (e.g., one of theappsubdirectories,lib, or a plugin’slibdirectory).
The bottom line is that you should rarely need to explicitly load Ruby code in your Rails applications (using require) if you follow the naming conventions.
You might be wondering what that builtin_directories method in Listing 1.1 is all about in the default_load_paths method. It is the place for Rails to include application behavior (meaning models, helpers, and controllers). You can think about it as kind of like a framework-provided plugin mechanism.
The only builtin that exists at this time is in railties/builtin/rails_info and it isn’t particularly well-known, other than as the target of the “About your application’s environment” link on the default “Welcome Aboard” index.html page that can be seen in a newly created Rails application.
To check it out, fire up any Rails application in development mode and go to http://localhost:3000/rails/info/properties via your browser. You’ll see a diagnostic screen with a dump of significant version numbers and settings that looks something like this:
Ruby version 1.8.5 (i686-darwin8.8.1) RubyGems version 0.9.0 Rails version 1.2.0 Active Record version 1.14.4 Action Pack version 1.12.5 Action Web Service version 1.1.6 Action Mailer version 1.2.5 Active Support version 1.3.1 Edge Rails revision 33 Application root /Users/obie/prorails/time_and_expenses Environment development Database adapter mysql Database schema version 8
Back to the environment script, where we’re about to get into developer-defined settings. The next couple of lines read as follows:
Rails::Initializer.run do |config| # Settings in config/environments/* take precedence over # those specified here
The comment reminds you that the settings in the mode-specific environment files will take precedence over settings in environment.rb, which is essentially because they are loaded afterward and will overwrite your settings.
The first setting gives you the option of not loading parts of the Rails that you might not be using. (Ruby is, of course, interpreted, and if you can get away with a smaller-sized codebase for the interpreter to parse, you should do so, simply for performance reasons.) Quite a few Rails applications do not use email or Web services, which is why they are given as examples:
# Skip frameworks you're not going to use (only works if # using vendor/rails) config.frameworks -= [ :action_web_service, :action_mailer ]
In the rare case of needing to add to the default load paths, the option is given to do so next:
# Add additional load paths for your own custom dirs
config.load_paths += %W( #{RAILS_ROOT}/extras )In case you didn’t know, the %W functions as a whitespace-delimited array literal and is used quite often in the Rails codebase for convenience. (I do admit it was a little off-putting for me at first as a long-time Java programmer.)
I’m tempted to say that the additional load paths option is not really needed, since you’ll want to extend Rails by writing plugins, which have their own convention for load paths. Chapter 19, “Extending Rails with Plugins,” covers the subject, and a companion book to this one in the Addison-Wesley Professional Ruby Series, Rails Plugins: Extending Rails Beyond the Core (ISBN: 0-321-48351-0) by James Adam, is an exhaustive reference about authoring plugins.
Notice how the last two settings were not settings in the traditional sense of plain assignment of an option value to a property. Rails takes full advantage of Ruby in letting you remove and add from an array in its configuration object.
The default log level is :debug and you can override it if necessary.
# Force all environments to use the same logger level # (by default production uses :info, the others :debug) config.log_level = :debug
This book covers use of the Rails logger in-depth later on in this chapter.
If you want to store user sessions in the database (and you definitely do in almost all production scenarios), this is where to set that option:
# Use the database for sessions instead of the file system # (create the session table with 'rake db:sessions:create') config.action_controller.session_store = :active_record_store
This book covers configuration and implications of ActiveRecord session store in Chapter 13, “Session Management.”
Every time you run tests, Rails dumps the schema of your development database and copies it to the test database using an autogenerated schema.rb script. It looks very similar to an ActiveRecord migration script; in fact, it uses the same API.
You might find it necessary to revert to the older style of dumping the schema using SQL, if you’re doing things that are incompatible with the schema dumper code (see the comment).
# Use SQL instead of Active Record's schema dumper when creating the # test database. This is necessary if your schema can't be completely # dumped by the schema dumper, for example, if you have constraints # or db-specific column types config.active_record.schema_format = :sql
ActiveRecord observers are first-class objects in your Rails applications that perform specific tasks such as clearing caches and managing denormalized data. The examples in the default environment.rb are just that, examples of classes that you might theoretically be writing in your application as observers. (There aren’t actually cacher or garbage_collector observers provided by Rails, but don’t take that to mean that Ruby doesn’t do garbage collection!)
# Activate observers that should always be running # config.active_record.observers = :cacher, :garbage_collector
This book covers ActiveRecord observers in-depth in Chapter 9, “Advanced ActiveRecord.”
The default time zone for Rails is local time (using Time.local), that is, the same time zone as your server. You can change the time zone that Rails picks up as your local time zone by modifying the TZ environment variable.
The list of time zones is typically in your /usr/share/zoneinfo folder. If you’re on a Mac, check the contents of /usr/share/zoneinfo/zone.tab for a list of valid zone names. Keep in mind that this solution, and particularly what values to use, is operating system-specific and said operating system might have already set it to the appropriate value on your behalf.
You can set the value of TZ code anywhere, but if you want to change it for your entire web application, you might as well put it in environment.rb, near the other time zone settings.
ENV['TZ'] = 'US/Eastern'
What if you want to support user-specific time zones? The first step is to tell ActiveRecord to record time in the database as UTC (using Time.utc).
# Make Active Record use UTC-base instead of local time config.active_record.default_timezone = :utc
Then you’ll need a way to convert back and forth to a time zone specified in association with your user. Unfortunately, the standard Rails TimeZone class doesn’t handle Daylight Saving Time (DST), which frankly makes it quite useless.
There is a pure-Ruby gem called TZInfo[1] with a TimeZone class that does correctly handle DST and can be dropped in as a replacement to the one in Rails. To use it in your application you will need to install both the tzinfo gem and the tzinfo_timezone plugin. However, that solution is pure Ruby and reportedly quite slow (although it might be fast enough for your needs).
Wait a minute—doesn’t Ruby’s Time class already understand how to deal with DST correctly?
>> Time.now => Mon Nov 27 16:32:51 -0500 2006 >> Time.now.getgm => Mon Nov 27 21:32:56 UTC 2006
The output in the console listing is in fact correct. So writing our own conversion routine shouldn’t be too hard, should it?
In a post to the rails-mailing-list in August 2006[2], Grzegorz Daniluk gives us an example of how to do just that (and benchmarks it at seven to nine times faster than TZInfo). You would add the following code to one of your application’s helper modules or put it in its own class within the lib folder:
# to convert posted date/time to UTC and save to DB def user2utc(t) ENV["TZ"] = current_user.time_zone_name res = Time.local(t.year, t.month, t.day, t.hour, t.min, t.sec).utc ENV["TZ"] = "UTC" res end # to display date/time in a view def utc2user(t) ENV["TZ"] = current_user.time_zone_name res = t.getlocal ENV["TZ"] = "UTC" res end
In a detailed response to the mailing list, the author of TZInfo, Philip Ross, informs us that the preceding solution does not work for Windows users.[3] He also comments about the handling of invalid times: “Another area TZInfo improves upon using the TZ environment variable is in its handling of invalid and ambiguous local times (i.e., during the transitions to and from daylight savings). Time.local always returns a time regardless of whether it was invalid or ambiguous. TZInfo reports invalid times and allows the ambiguity to be resolved by specifying whether to use the DST or non-DST time or running a block to do the selection.”
To summarize, don’t use Windows. No, just kidding. The real lesson from this issue is that handling time zones correctly is not an easy affair and should be considered very carefully.
That does it for the configuration options for which we get examples in the default environment.rb. There are additional options, which I suspect that you will rarely need to use or know about. If you want to see the whole list, look at the source code and docs for the Configuration class starting around line 400 of the file railties/lib/initializer.rb.
Remember we said that the value of the RAILS_ENV environment variable dictates which additional environment settings are loaded next? So now let’s review the default settings for each of Rails’ standard modes.
Development is Rails’ default mode and the one in which you will spend most of your time as a developer:
# Settings specified here will take precedence over those in # config/environment.rb # In the development environment your application's code is reloaded on # every request. This slows down response time but is perfect for # development since you don't have to restart the webserver when you # make code changes. config.cache_classes = false # Log error messages when you accidentally call methods on nil. config.whiny_nils = true # Enable the breakpoint server that script/breakpointer connects to config.breakpoint_server = true # Show full error reports and disable caching config.action_controller.consider_all_requests_local = true config.action_controller.perform_caching = false config.action_view.cache_template_extensions = false config.action_view.debug_rjs = true # Don't care if the mailer can't send config.action_mailer.raise_delivery_errors = false
In the following sections I cover the important settings in depth, starting with the caching of classes: the setting that makes Rails’ dynamic class reloading possible.
One of the signature benefits of using Rails is the quick feedback cycle whenever you’re working in development mode. Make changes to your code, hit Reload in the browser, and Shazam! Magically, the changes are reflected in your application. This behavior is governed by the config.cache_classes setting, which you see is set to false at the top of config/environments/development.rb.
Without getting into too much nitty-gritty detail, when the config.cache_classes setting is true, Rails will use Ruby’s require statement to do its class loading, and when it is false, it will use load instead.
When you require a Ruby file, the interpreter executes and caches it. If the file is required again (as in subsequent requests), the interpreter ignores the request statement and moves on. When you load a Ruby file, the interpreter executes the file again, no matter how many times it has been loaded before.
Now it’s time to examine the Rails class-loading behavior a bit more in depth, because sometimes you won’t be able to get certain things to reload automatically and it will drive you crazy unless you understand how class loading works!
In plain old Ruby, a script file doesn’t need to be named in any particular way that matches its contents. In Rails, however, you’ll notice that there’s almost always a direct correlation between the name of a Ruby file and the class contained within. Rails takes advantage of the fact that Ruby provides a callback mechanism for missing constants. When Rails encounters an undefined constant in the code, it uses a classloader routine based on file-naming conventions to find and require the needed Ruby script.
How does the classloader know where to search? We already covered it earlier in the chapter where we discussed the role of initializer.rb in the Rails startup process. Rails has the concept of load paths, and the default load paths include the base directories of just about anywhere you would think of adding code to your Rails application.
The default_load_paths method shows you the order in which Rails searches the directories in its load path. We’ll dissect the source of this method here and explain the reason behind each part of the load path.
The test/mocks directory (covered more extensively in Chapter 17, “Testing,”) is provided to give you the ability to override the behavior of standard Rails classes.
paths = ["#{root_path}/test/mocks/#{environment}"]
# Add the app's controller directory
paths.concat(Dir["#{root_path}/app/controllers/"])
# Then components subdirectories.
paths.concat(Dir["#{root_path}/components/[_a-z]*"])
# Followed by the standard includes.
paths.concat %w(
app
app/models
app/controllers
app/helpers
app/services
app/apis
components
config
lib
vendor
).map { |dir| "#{root_path}/#{dir}" }.select { |dir|
File.directory?(dir) }
paths.concat Dir["#{root_path}/vendor/plugins/*/lib/"]
paths.concat builtin_directories
endWant to see the contents of your project’s load path? Just fire up the console and type $: as follows:
$ console Loading development environment. >> $: => ["/usr/local/lib/ruby/gems/1.8/gems/ ... # about 20 lines of output
I snipped the console output to save space. A typical Rails project load path will usually have 30 or more items in its load path. Try it and see.
Whenever you run Rails in test mode, that is, the value of the RAILS_ENV environment value is test, then the following settings are in effect:
# Settings specified here will take precedence over those in # config/environment.rb # The test environment is used exclusively to run your application's # test suite. You never need to work with it otherwise. Remember that # your test database is "scratch space" for the test suite and is wiped # and recreated between test runs. Don't rely on the data there! config.cache_classes = true # Log error messages when you accidentally call methods on nil. config.whiny_nils = true # Show full error reports and disable caching config.action_controller.consider_all_requests_local = true config.action_controller.perform_caching = false # Tell ActionMailer not to deliver emails to the real world. # The :test delivery method accumulates sent emails in the # ActionMailer::Base.deliveries array. config.action_mailer.delivery_method = :test
Most people get by without ever needing to modify their test environment settings.
Finally, production mode is what you want your Rails application running in whenever it is deployed to its hosting environment and serving public requests. There are a number of significant ways that production mode differs from the other modes, not least of which is the speed boost you get from not reloading all of your application classes for every request.
# Settings specified here will take precedence over those # in config/environment.rb # The production environment is meant for finished, "live" apps. # Code is not reloaded between requests config.cache_classes = true # Use a different logger for distributed setups # config.logger = SyslogLogger.new # Full error reports are disabled and caching is turned on config.action_controller.consider_all_requests_local = false config.action_controller.perform_caching = true # Enable serving of images, stylesheets, and javascripts # from an asset server # config.action_controller.asset_host = "http://assets.example.com" # Disable delivery errors, bad email addresses will be ignored # config.action_mailer.raise_delivery_errors = false
Most programming contexts in Rails (models, controllers, view templates) have a logger attribute, which holds a reference to a logger conforming to the interface of Log4r or the default Ruby 1.8+ Logger class. Can’t get a reference to logger somewhere in your code? The RAILS_DEFAULT_LOGGER global variable has a reference to the logger that you can use anywhere. It even has its own TextMate shortcut (rdb →).
It’s really easy to create a new Logger in Ruby, as shown in the following example:
$ irb > require 'logger' => true irb(main):002:0> logger = Logger.new STDOUT => #<Logger:0x32db4c @level=0, @progname=nil, @logdev= #<Logger::LogDevice:0x32d9bc ... > > logger.warn "do not want!!!" W, [2007-06-06T17:25:35.666927 #7303] WARN -- : do not want!!! => true > logger.info "in your logger, giving info" I, [2007-06-06T17:25:50.787598 #7303] INFO -- : in your logger, giving your info => true
Typically, you add a message to the log using the logger whenever the need arises, using a method corresponding to the severity of the log message. The standard logger’s severities are (in increasingly severe order):
debug. Use the debug level to capture data and application state useful for debugging problems later on. This level is not usually captured in production logs.
info. Use info level to capture informational messages. I like to use this log level for time-stamping non-ordinary events that are still within the bounds of good application behavior.
warn. Use the warn level to capture things that are out of the ordinary and might be worth investigating. Sometimes I’ll throw in a logged warning when guard clauses in my code keep a client from doing something they weren’t supposed to do. My goal is to alert whoever’s maintaining the application about a malicious user or bug in the user interface, as in the following example:
def create begin @group.add_member(current_user) flash[:notice] = "Successfully joined #{@scene.display_name}" rescue ActiveRecord::RecordInvalid flash[:error] = "You are already a member of #{@group.name}" logger.warn "A user tried to join a group twice. UI should not have allowed it." end redirect_to :back enderror. Use the error log level to capture information about error conditions that don’t require a server restart.
fatal. The worst-case imaginable has happened—your application is now dead and manual intervention is necessary to restart it.
The log folder of your Rails application holds three log files corresponding to each of the standard environments, plus a log and pid file for Mongrel. Log files can grow very large over time. A rake task is provided for easily clearing the log files:
rake log:clear # Truncates all *.log files in log/ to zero bytes
The contents of log/development.log are very useful while you’re working. Many Rails coders leave a terminal window open with a continuous tail of the development log open while they’re coding:
$ tail -f log/development.log User Load (0.000522) SELECT * FROM users WHERE (users.`id` = 1) CACHE (0.000000) SELECT * FROM users WHERE (users.`id` = 1)
All sorts of valuable information are available in the development log. For instance, every time you make a request, a bunch of useful information about it shows up in the log. Here’s a sample from one of my projects, followed by a list of all the data items it contains:
Processing UserPhotosController#show (for 127.0.0.1 at 2007-06-06
17:43:13) [GET]
Session ID: b362cf038810bb8dec076fcdaec3c009
Parameters: {"/users/8-Obie-Fernandez/photos/406"=>nil,
"action"=>"show", "id"=>"406", "controller"=>"user_photos",
"user_id"=>"8-Obie-Fernandez"}
User Load (0.000477) SELECT * FROM users WHERE (users.`id` = 8)
Photo Columns (0.003182) SHOW FIELDS FROM photos
Photo Load (0.000949) SELECT * FROM photos WHERE (photos.`id` = 406
AND (photos.resource_id = 8 AND photos.resource_type = 'User'))
Rendering template within layouts/application
Rendering photos/show
CACHE (0.000000) SELECT * FROM users WHERE (users.`id` = 8)
Rendered adsense/_medium_rectangle (0.00155)
User Load (0.000541) SELECT * FROM users WHERE (users.`id` = 8)
LIMIT 1
Message Columns (0.002225) SHOW FIELDS FROM messages
SQL (0.000439) SELECT count(*) AS count_all FROM messages WHERE
(messages.receiver_id = 8 AND (messages.`read` = 0))
Rendered layouts/_header (0.02535)
Rendered adsense/_leaderboard (0.00043)
Rendered layouts/_footer (0.00085)
Completed in 0.09895 (10 reqs/sec) | Rendering: 0.03740 (37%) | DB:
0.01233 (12%) | 200 OK [http://localhost/users/8-Obie-
Fernandez/photos/406]
User Columns (0.004578) SHOW FIELDS FROM usersThe controller and action that were invoked
The remote IP address of the computer making the request
A timestamp indicating when the request happened
The session ID associated with the request
The hash of parameters associated with the request
Database request information including the time and the SQL statement executed
Query cache hit info including time and the SQL statement triggering results from the cache instead of a roundtrip to the database
Rendering information for each template involved in rendering the view output and time consumed by each
Total time used in completing the request with corresponding request-per-second figures
Analysis of the time spent in database operations versus rendering
The HTTP status code and URL of the response sent back to the client
A number of informal analyses can be easily performed using just the development log output and some common sense.
Performance. One of the more obvious analyses would be a study of the performance of your application. The faster your requests execute, the more requests you can serve with a given Rails process. That’s why performance figures are often expressed in terms of requests per second. Find the queries and rendering sections that are taking a long time and figure out why.
It’s important to realize that the times reported by the logger are not super-accurate. In fact, they’re wrong more often than not, if simply for the reason that it’s very difficult to measure the timing of something from within itself. Add up the percentage of rendering and database times for any given request and it will not always be close to 100%.
However, despite not being accurate in a purely objective sense, the reported times are perfect for making subjective comparisons within the same application. They give you a way of gauging whether an action is taking longer than it used to, or whether it is relatively faster or slower than another action, and so on.
SQL queries.
ActiveRecordnot behaving as expected? The fact that SQL generated byActiveRecordis logged can often help you debug problems caused by complicated queries.Identification of N+1 select problems. Whenever you are displaying a record along with an associated collection of records, there’s a chance that you will have a so-called N+1 select problem. You’ll recognize the problem by a series of many
SELECTstatements, with the only difference being the value of the primary key.
For example, here’s a snippet of some log output from a real Rails application showing an N+1 select issue in the way that FlickrPhoto instances are being loaded:
FlickrPhoto Load (0.001395) SELECT * FROM flickr_photos WHERE (flickr_photos.resource_id = 15749 AND flickr_photos.resource_type = 'Place' AND (flickr_photos.`profile` = 1)) ORDER BY updated_at desc LIMIT 1 FlickrPhoto Load (0.001734) SELECT * FROM flickr_photos WHERE (flickr_photos.resource_id = 15785 AND flickr_photos.resource_type = 'Place' AND (flickr_photos.`profile` = 1)) ORDER BY updated_at desc LIMIT 1 FlickrPhoto Load (0.001440) SELECT * FROM flickr_photos WHERE (flickr_photos.resource_id = 15831 AND flickr_photos.resource_type = 'Place' AND (flickr_photos.`profile` = 1)) ORDER BY updated_at desc LIMIT 1
... and so on and so forth, for pages and pages of log output. Look familiar?
Luckily, each of those database queries is executing very quickly, around 0.0015 seconds each. That’s because 1) MySQL is extraordinarily fast for small SELECT statements and 2) my Rails process is on the same physical machine as the database.
Still, accumulate enough of those N queries and they add up quickly to eat away at performance. Absent the mitigating factors I mentioned, I would have a serious performance problem to address. The problem would be especially severe if the database was on a separate machine, giving me network latency to deal with on each of those queries.
N+1 select issues are not the end of the world. A lot of times all it takes is proper use of an :include option on a particular find method call to alleviate the problem.
Separation of concerns. A well-designed model-view-controller application follows certain protocols related to which logical tier does database operations (that would be the model) versus rendering tasks (the view). Generally speaking, you want your controller to cause the loading of all of the data that is going to be needed for rendering from the database. In Rails, it is accomplished by controller code that queries the model for needed data and stores that data in instance variables to be consumed by the view.
Database access during rendering is usually considered a bad practice. Calling find methods directly from template code violates proper separation of concerns and is a maintainability nightmare.[4]
However, there are plenty of opportunities for implicit database access during view rendering to creep into your codebase, encapsulated by the model, and perhaps triggered by lazy loading of associations. Can we conclusively call it a bad practice? It’s hard to say so definitively. There are cases (such as usage of fragment caching) where it makes sense to have database operations happening during view rendering.
UNIX-like systems have a system service called syslog. For various reasons, it might be a better choice for production logging of your Rails applications.
Finer-grained control over logging levels and content.
Consolidation of logger output for multiple Rails applications.
If you’re using remote syslog capabilities of many systems, consolidation of logger output for multiple Rails application servers is possible. Contrast with having to handle individual log files on each application server box separately.
You can use Eric Hodel’s SyslogLogger[5] to interface your Rails application to syslog. Setup will involve downloading the library, requiring it in your environment.rb file, and replacing the RAILS_DEFAULT_LOGGER instance.
We’ve kicked off our Rails journey by reviewing the different environments in which Rails executes and how it loads its dependencies, including your application code. An in-depth look at environment.rb and its per-mode variants revealed how we can customize Rails behavior to our taste. In discussing the version of Rails libraries used for a particular project, we also had an opportunity to discuss running edge and whether it might make sense for your project.
We also learned about the Rails startup process by actually taking a peek at some of its source code. (Throughout the rest of the book, we’ll dive into Rails source code wherever it makes sense to do so.)
In Chapter 2, “Working with Controllers,” we continue our journey by delving into the Rails dispatcher and the ActionController framework.