rails/railties
schneems 81d3bec460 Default new apps to tag logs with request_id
In high volume applications it can be very difficult to figure out what is happening in logs because each request is not easily identified. For example 3 requests could look something like this:

```
Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:21 +0000
  Rendered welcome/index.html.erb within layouts/application (0.1ms)
Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:22 +0000
Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:23 +0000
  Rendered welcome/index.html.erb within layouts/application (0.1ms)
Processing by WelcomeController#index as HTML
Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
Processing by WelcomeController#index as HTML
  Rendered welcome/index.html.erb within layouts/application (0.1ms)
Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
  Processing by WelcomeController#index as HTML
Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
```

The `:request_id` log tag ensures that each request is tagged with a unique identifier. While they are still interleaved it is possible to figure out which lines belong to which requests. Like:

```
[c6034478-4026-4ded-9e3c-088c76d056f1] Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:21 +0000
[c6034478-4026-4ded-9e3c-088c76d056f1]  Rendered welcome/index.html.erb within layouts/application (0.1ms)
[abuqw781-5026-6ded-7e2v-788c7md0L6fQ] Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:22 +0000
[acfab2a7-f1b7-4e15-8bf6-cdaa008d102c] Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:23 +0000
[abuqw781-5026-6ded-7e2v-788c7md0L6fQ]  Rendered welcome/index.html.erb within layouts/application (0.1ms)
[c6034478-4026-4ded-9e3c-088c76d056f1] Processing by WelcomeController#index as HTML
[c6034478-4026-4ded-9e3c-088c76d056f1] Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
[abuqw781-5026-6ded-7e2v-788c7md0L6fQ] Processing by WelcomeController#index as HTML
[abuqw781-5026-6ded-7e2v-788c7md0L6fQ]  Rendered welcome/index.html.erb within layouts/application (0.1ms)
[abuqw781-5026-6ded-7e2v-788c7md0L6fQ] Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
[acfab2a7-f1b7-4e15-8bf6-cdaa008d102c]  Processing by WelcomeController#index as HTML
[acfab2a7-f1b7-4e15-8bf6-cdaa008d102c] Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
```

Now if you have the logs and you find this unique ID you can filter to only look at information from that request. So a filtered log output would be very clear:

```
[c6034478-4026-4ded-9e3c-088c76d056f1] Started GET "/" for 72.48.77.213 at 2016-01-06 20:30:21 +0000
[c6034478-4026-4ded-9e3c-088c76d056f1]  Rendered welcome/index.html.erb within layouts/application (0.1ms)
[c6034478-4026-4ded-9e3c-088c76d056f1] Processing by WelcomeController#index as HTML
[c6034478-4026-4ded-9e3c-088c76d056f1] Completed 200 OK in 5ms (Views: 3.8ms | ActiveRecord: 0.0ms)
```

In addition to this benefit the `:request_id` can be set via the `X-Request-ID` header so that the same request could be traced between multiple components. For example a request comes in Nginx (or another load balancer) could assign a request id. As the load balancer processes the request I can log using that id, then when the request is passed on to Rails, the same id is used. That way if a problem is determined to be not caused in Rails it could be traced back to other components with the same ID. You can set a value in nginx for example using something like this:

```
  location / {
      proxy_pass http://upstream;
      proxy_set_header X-Request-Id $pid-$msec-$remote_addr-$request_length;
  }
# http://stackoverflow.com/questions/17748735/setting-a-trace-id-in-nginx-load-balancer
```

Heroku sets this header value so problems like timeouts that are logged by like router can be traced back to specific request within the application.

Whether you are using components that are setting request ID or not, all production applications can benefit from the additional debugging information of having a unique identifier for all requests. This change will only affect new applications, anyone can opt out by commenting or removing the line in `config/production.rb`.
2016-01-06 15:26:22 -06:00
..
exe Rename railties/bin to railties/exe 2015-04-11 19:26:34 +02:00
lib Default new apps to tag logs with request_id 2016-01-06 15:26:22 -06:00
test Default new apps to tag logs with request_id 2016-01-06 15:26:22 -06:00
.gitignore
CHANGELOG.md release notes, extract notable changes from Railties CHANGELOG. 2015-12-22 10:59:45 +01:00
MIT-LICENSE Update copyright notices to 2016 [ci skip] 2015-12-31 18:27:19 +02:00
railties.gemspec Include MIT-LICENSE in railties gem 2015-09-01 14:17:10 -04:00
Rakefile Revert "don't start a new process for every test file" 2015-12-02 15:34:42 -05:00
RDOC_MAIN.rdoc Fix Rails tutorial link 2015-12-21 17:25:09 -08:00
README.rdoc Feature requests should be made on the mailing list, not submitted to 2014-06-01 19:11:39 -07:00

= Railties -- Gluing the Engine to the Rails

Railties is responsible for gluing all frameworks together. Overall, it:

* handles the bootstrapping process for a Rails application;

* manages the +rails+ command line interface;

* and provides the Rails generators core.


== Download

The latest version of Railties can be installed with RubyGems:

* gem install railties

Source code can be downloaded as part of the Rails project on GitHub

* https://github.com/rails/rails/tree/master/railties

== License

Railties is released under the MIT license:

* http://www.opensource.org/licenses/MIT

== Support

API documentation is at

* http://api.rubyonrails.org

Bug reports can be filed for the Ruby on Rails project here:

* https://github.com/rails/rails/issues

Feature requests should be discussed on the rails-core mailing list here:

* https://groups.google.com/forum/?fromgroups#!forum/rubyonrails-core