diff options
Diffstat (limited to 'guides/source/debugging_rails_applications.md')
| -rw-r--r-- | guides/source/debugging_rails_applications.md | 180 |
1 files changed, 90 insertions, 90 deletions
diff --git a/guides/source/debugging_rails_applications.md b/guides/source/debugging_rails_applications.md index a5a22a8a8f..2c8e440e55 100644 --- a/guides/source/debugging_rails_applications.md +++ b/guides/source/debugging_rails_applications.md @@ -21,17 +21,17 @@ h4. +debug+ The +debug+ helper will return a <pre>-tag that renders the object using the YAML format. This will generate human-readable data from any object. For example, if you have this code in a view: -<html> +```html <%= debug @post %> <p> <b>Title:</b> <%=h @post.title %> </p> -</html> +``` You'll see something like this: -<yaml> +```yaml --- !ruby/object:Post attributes: updated_at: 2008-09-05 22:55:47 @@ -44,25 +44,25 @@ attributes_cache: {} Title: Rails debugging guide -</yaml> +``` h4. +to_yaml+ Displaying an instance variable, or any other object or method, in YAML format can be achieved this way: -<html> +```html <%= simple_format @post.to_yaml %> <p> <b>Title:</b> <%=h @post.title %> </p> -</html> +``` The +to_yaml+ method converts the method to YAML format leaving it more readable, and then the +simple_format+ helper is used to render each line as in the console. This is how +debug+ method does its magic. As a result of this, you will have something like this in your view: -<yaml> +```yaml --- !ruby/object:Post attributes: updated_at: 2008-09-05 22:55:47 @@ -74,27 +74,27 @@ created_at: 2008-09-05 22:55:47 attributes_cache: {} Title: Rails debugging guide -</yaml> +``` h4. +inspect+ Another useful method for displaying object values is +inspect+, especially when working with arrays or hashes. This will print the object value as a string. For example: -<html> +```html <%= [1, 2, 3, 4, 5].inspect %> <p> <b>Title:</b> <%=h @post.title %> </p> -</html> +``` Will be rendered as follows: -<pre> +``` [1, 2, 3, 4, 5] Title: Rails debugging guide -</pre> +``` h3. The Logger @@ -106,17 +106,17 @@ Rails makes use of the +ActiveSupport::BufferedLogger+ class to write log inform You can specify an alternative logger in your +environment.rb+ or any environment file: -<ruby> +```ruby Rails.logger = Logger.new(STDOUT) Rails.logger = Log4r::Logger.new("Application Log") -</ruby> +``` Or in the +Initializer+ section, add _any_ of the following -<ruby> +```ruby config.logger = Logger.new(STDOUT) config.logger = Log4r::Logger.new("Application Log") -</ruby> +``` TIP: By default, each log is created under +Rails.root/log/+ and the log file name is +environment_name.log+. @@ -126,10 +126,10 @@ When something is logged it's printed into the corresponding log if the log leve The available log levels are: +:debug+, +:info+, +:warn+, +:error+, +:fatal+, and +:unknown+, corresponding to the log level numbers from 0 up to 5 respectively. To change the default log level, use -<ruby> +```ruby config.log_level = :warn # In any environment initializer, or Rails.logger.level = 0 # at any time -</ruby> +``` This is useful when you want to log under development or staging, but you don't want to flood your production log with unnecessary information. @@ -139,15 +139,15 @@ h4. Sending Messages To write in the current log use the +logger.(debug|info|warn|error|fatal)+ method from within a controller, model or mailer: -<ruby> +```ruby logger.debug "Person attributes hash: #{@person.attributes.inspect}" logger.info "Processing the request..." logger.fatal "Terminating application, raised unrecoverable error!!!" -</ruby> +``` Here's an example of a method instrumented with extra logging: -<ruby> +```ruby class PostsController < ApplicationController # ... @@ -167,11 +167,11 @@ class PostsController < ApplicationController # ... end -</ruby> +``` Here's an example of the log generated by this method: -<shell> +```shell Processing PostsController#create (for 127.0.0.1 at 2008-09-08 11:52:54) [POST] Session ID: BAh7BzoMY3NyZl9pZCIlMDY5MWU1M2I1ZDRjODBlMzkyMWI1OTg2NWQyNzViZjYiCmZsYXNoSUM6J0FjdGl vbkNvbnRyb2xsZXI6OkZsYXNoOjpGbGFzaEhhc2h7AAY6CkB1c2VkewA=--b18cd92fba90eacf8137e5f6b3b06c4d724596a4 @@ -187,7 +187,7 @@ Post should be valid: true The post was saved and now the user is going to be redirected... Redirected to #<Post:0x20af760> Completed in 0.01224 (81 reqs/sec) | DB: 0.00044 (3%) | 302 Found [http://localhost/posts] -</shell> +``` Adding extra logging like this makes it easy to search for unexpected or unusual behavior in your logs. If you add extra logging, be sure to make sensible use of log levels, to avoid filling your production logs with useless trivia. @@ -212,38 +212,38 @@ h4. Setup Rails uses the +debugger+ gem to set breakpoints and step through live code. To install it, just run: -<shell> +```shell $ gem install debugger -</shell> +``` Rails has had built-in support for debugging since Rails 2.0. Inside any Rails application you can invoke the debugger by calling the +debugger+ method. Here's an example: -<ruby> +```ruby class PeopleController < ApplicationController def new debugger @person = Person.new end end -</ruby> +``` If you see the message in the console or logs: -<shell> +```shell ***** Debugger requested, but was not available: Start server with --debugger to enable ***** -</shell> +``` Make sure you have started your web server with the option +--debugger+: -<shell> +```shell $ rails server --debugger => Booting WEBrick => Rails 3.0.0 application starting on http://0.0.0.0:3000 => Debugger enabled ... -</shell> +``` TIP: In development mode, you can dynamically +require \'debugger\'+ instead of restarting the server, if it was started without +--debugger+. @@ -255,14 +255,14 @@ If you got there by a browser request, the browser tab containing the request wi For example: -<shell> +```shell @posts = Post.all (rdb:7) -</shell> +``` Now it's time to explore and dig into your application. A good place to start is by asking the debugger for help... so type: +help+ (You didn't see that coming, right?) -<shell> +```shell (rdb:7) help ruby-debug help v0.10.2 Type 'help <command-name>' for help on a specific command @@ -273,7 +273,7 @@ break disable eval info p reload source undisplay catch display exit irb pp restart step up condition down finish list ps save thread var continue edit frame method putl set tmate where -</shell> +``` TIP: To view the help menu for any command use +help <command-name>+ in active debug mode. For example: _+help var+_ @@ -281,7 +281,7 @@ The next command to learn is one of the most useful: +list+. You can abbreviate This command shows you where you are in the code by printing 10 lines centered around the current line; the current line in this particular case is line 6 and is marked by +=>+. -<shell> +```shell (rdb:7) list [1, 10] in /PathToProject/posts_controller.rb 1 class PostsController < ApplicationController @@ -294,11 +294,11 @@ This command shows you where you are in the code by printing 10 lines centered a 8 respond_to do |format| 9 format.html # index.html.erb 10 format.json { render :json => @posts } -</shell> +``` If you repeat the +list+ command, this time using just +l+, the next ten lines of the file will be printed out. -<shell> +```shell (rdb:7) l [11, 20] in /PathTo/project/app/controllers/posts_controller.rb 11 end @@ -311,13 +311,13 @@ If you repeat the +list+ command, this time using just +l+, the next ten lines o 18 19 respond_to do |format| 20 format.html # show.html.erb -</shell> +``` And so on until the end of the current file. When the end of file is reached, the +list+ command will start again from the beginning of the file and continue again up to the end, treating the file as a circular buffer. On the other hand, to see the previous ten lines you should type +list-+ (or +l-+) -<shell> +```shell (rdb:7) l- [1, 10] in /PathToProject/posts_controller.rb 1 class PostsController < ApplicationController @@ -330,12 +330,12 @@ On the other hand, to see the previous ten lines you should type +list-+ (or +l- 8 respond_to do |format| 9 format.html # index.html.erb 10 format.json { render :json => @posts } -</shell> +``` This way you can move inside the file, being able to see the code above and over the line you added the +debugger+. Finally, to see where you are in the code again you can type +list=+ -<shell> +```shell (rdb:7) list= [1, 10] in /PathToProject/posts_controller.rb 1 class PostsController < ApplicationController @@ -348,7 +348,7 @@ Finally, to see where you are in the code again you can type +list=+ 8 respond_to do |format| 9 format.html # index.html.erb 10 format.json { render :json => @posts } -</shell> +``` h4. The Context @@ -358,7 +358,7 @@ The debugger creates a context when a stopping point or an event is reached. The At any time you can call the +backtrace+ command (or its alias +where+) to print the backtrace of the application. This can be very helpful to know how you got where you are. If you ever wondered about how you got somewhere in your code, then +backtrace+ will supply the answer. -<shell> +```shell (rdb:5) where #0 PostsController.index at line /PathTo/project/app/controllers/posts_controller.rb:6 @@ -369,15 +369,15 @@ At any time you can call the +backtrace+ command (or its alias +where+) to print #3 ActionController::Filters::InstanceMethods.call_filters(chain#ActionController::Fil...,...) at line /PathTo/project/vendor/rails/actionpack/lib/action_controller/filters.rb:617 ... -</shell> +``` You move anywhere you want in this trace (thus changing the context) by using the +frame _n_+ command, where _n_ is the specified frame number. -<shell> +```shell (rdb:5) frame 2 #2 ActionController::Base.perform_action_without_filters at line /PathTo/project/vendor/rails/actionpack/lib/action_controller/base.rb:1175 -</shell> +``` The available variables are the same as if you were running the code line by line. After all, that's what debugging is. @@ -401,29 +401,29 @@ Any expression can be evaluated in the current context. To evaluate an expressio This example shows how you can print the instance_variables defined within the current context: -<shell> +```shell @posts = Post.all (rdb:11) instance_variables ["@_response", "@action_name", "@url", "@_session", "@_cookies", "@performed_render", "@_flash", "@template", "@_params", "@before_filter_chain_aborted", "@request_origin", "@_headers", "@performed_redirect", "@_request"] -</shell> +``` As you may have figured out, all of the variables that you can access from a controller are displayed. This list is dynamically updated as you execute code. For example, run the next line using +next+ (you'll learn more about this command later in this guide). -<shell> +```shell (rdb:11) next Processing PostsController#index (for 127.0.0.1 at 2008-09-04 19:51:34) [GET] Session ID: BAh7BiIKZmxhc2hJQzonQWN0aW9uQ29udHJvbGxlcjo6Rmxhc2g6OkZsYXNoSGFzaHsABjoKQHVzZWR7AA==--b16e91b992453a8cc201694d660147bba8b0fd0e Parameters: {"action"=>"index", "controller"=>"posts"} /PathToProject/posts_controller.rb:8 respond_to do |format| -</shell> +``` And then ask again for the instance_variables: -<shell> +```shell (rdb:11) instance_variables.include? "@posts" true -</shell> +``` Now +@posts+ is included in the instance variables, because the line defining it was executed. @@ -431,38 +431,38 @@ TIP: You can also step into *irb* mode with the command +irb+ (of course!). This The +var+ method is the most convenient way to show variables and their values: -<shell> +```shell var (rdb:1) v[ar] const <object> show constants of object (rdb:1) v[ar] g[lobal] show global variables (rdb:1) v[ar] i[nstance] <object> show instance variables of object (rdb:1) v[ar] l[ocal] show local variables -</shell> +``` This is a great way to inspect the values of the current context variables. For example: -<shell> +```shell (rdb:9) var local __dbg_verbose_save => false -</shell> +``` You can also inspect for an object method this way: -<shell> +```shell (rdb:9) var instance Post.new @attributes = {"updated_at"=>nil, "body"=>nil, "title"=>nil, "published"=>nil, "created_at"... @attributes_cache = {} @new_record = true -</shell> +``` TIP: The commands +p+ (print) and +pp+ (pretty print) can be used to evaluate Ruby expressions and display the value of variables to the console. You can use also +display+ to start watching variables. This is a good way of tracking the values of a variable while the execution goes on. -<shell> +```shell (rdb:1) display @recent_comments 1: @recent_comments = -</shell> +``` The variables inside the displaying list will be printed with their values after you move in the stack. To stop displaying a variable use +undisplay _n_+ where _n_ is the variable number (1 in the last example). @@ -480,7 +480,7 @@ The difference between +next+ and +step+ is that +step+ stops at the next line o For example, consider this block of code with an included +debugger+ statement: -<ruby> +```ruby class Author < ActiveRecord::Base has_one :editorial has_many :comments @@ -490,11 +490,11 @@ class Author < ActiveRecord::Base @recent_comments ||= comments.where("created_at > ?", 1.week.ago).limit(limit) end end -</ruby> +``` TIP: You can use the debugger while using +rails console+. Just remember to +require "debugger"+ before calling the +debugger+ method. -<shell> +```shell $ rails console Loading development environment (Rails 3.1.0) >> require "debugger" @@ -504,11 +504,11 @@ Loading development environment (Rails 3.1.0) >> author.find_recent_comments /PathTo/project/app/models/author.rb:11 ) -</shell> +``` With the code stopped, take a look around: -<shell> +```shell (rdb:1) list [2, 9] in /PathTo/project/app/models/author.rb 2 has_one :editorial @@ -519,19 +519,19 @@ With the code stopped, take a look around: => 7 @recent_comments ||= comments.where("created_at > ?", 1.week.ago).limit(limit) 8 end 9 end -</shell> +``` You are at the end of the line, but... was this line executed? You can inspect the instance variables. -<shell> +```shell (rdb:1) var instance @attributes = {"updated_at"=>"2008-07-31 12:46:10", "id"=>"1", "first_name"=>"Bob", "las... @attributes_cache = {} -</shell> +``` +@recent_comments+ hasn't been defined yet, so it's clear that this line hasn't been executed yet. Use the +next+ command to move on in the code: -<shell> +```shell (rdb:1) next /PathTo/project/app/models/author.rb:12 @recent_comments @@ -540,7 +540,7 @@ You are at the end of the line, but... was this line executed? You can inspect t @attributes_cache = {} @comments = [] @recent_comments = [] -</shell> +``` Now you can see that the +@comments+ relationship was loaded and @recent_comments defined because the line was executed. @@ -556,26 +556,26 @@ You can add breakpoints dynamically with the command +break+ (or just +b+). Ther * +break file:line [if expression]+: set breakpoint in the _line_ number inside the _file_. If an _expression_ is given it must evaluated to _true_ to fire up the debugger. * +break class(.|\#)method [if expression]+: set breakpoint in _method_ (. and \# for class and instance method respectively) defined in _class_. The _expression_ works the same way as with file:line. -<shell> +```shell (rdb:5) break 10 Breakpoint 1 file /PathTo/project/vendor/rails/actionpack/lib/action_controller/filters.rb, line 10 -</shell> +``` Use +info breakpoints _n_+ or +info break _n_+ to list breakpoints. If you supply a number, it lists that breakpoint. Otherwise it lists all breakpoints. -<shell> +```shell (rdb:5) info breakpoints Num Enb What 1 y at filters.rb:10 -</shell> +``` To delete breakpoints: use the command +delete _n_+ to remove the breakpoint number _n_. If no number is specified, it deletes all breakpoints that are currently active.. -<shell> +```shell (rdb:5) delete 1 (rdb:5) info breakpoints No breakpoints. -</shell> +``` You can also enable or disable breakpoints: @@ -623,11 +623,11 @@ TIP: You can save these settings in an +.rdebugrc+ file in your home directory. Here's a good start for an +.rdebugrc+: -<shell> +```shell set autolist set forcestep set listsize 25 -</shell> +``` h3. Debugging Memory Leaks @@ -643,33 +643,33 @@ If a Ruby object does not go out of scope, the Ruby Garbage Collector won't swee To install it run: -<shell> +```shell $ gem install bleak_house -</shell> +``` Then setup your application for profiling. Then add the following at the bottom of config/environment.rb: -<ruby> +```ruby require 'bleak_house' if ENV['BLEAK_HOUSE'] -</ruby> +``` Start a server instance with BleakHouse integration: -<shell> +```shell $ RAILS_ENV=production BLEAK_HOUSE=1 ruby-bleak-house rails server -</shell> +``` Make sure to run a couple hundred requests to get better data samples, then press +CTRL-C+. The server will stop and Bleak House will produce a dumpfile in +/tmp+: -<shell> +```shell ** BleakHouse: working... ** BleakHouse: complete ** Bleakhouse: run 'bleak /tmp/bleak.5979.0.dump' to analyze. -</shell> +``` To analyze it, just run the listed command. The top 20 leakiest lines will be listed: -<shell> +```shell 191691 total objects Final heap size 191691 filled, 220961 free Displaying top 20 most common line/class pairs @@ -682,7 +682,7 @@ To analyze it, just run the listed command. The top 20 leakiest lines will be li 935 /opt/local//lib/ruby/site_ruby/1.8/rubygems/specification.rb:557:String 834 /opt/local//lib/ruby/site_ruby/1.8/rubygems/version.rb:146:Array ... -</shell> +``` This way you can find where your application is leaking memory and fix it. |