Rails 5 supports logging errors with tagged logging

We use tagged logging to better extract information from logs generated by Rails applications.

Consider a Rails 4.x application where the request id is used as a log tag by adding following in config/environments/production.rb.

1config.log_tags = [:uuid]
Copy

The log generated for that application would look like:

1[df88dbaa-50fd-4178-85d7-d66279ea33b6] Started GET "/posts" for ::1 at 2016-06-03 17:19:32 +0530
2[df88dbaa-50fd-4178-85d7-d66279ea33b6] Processing by PostsController#index as HTML
3[df88dbaa-50fd-4178-85d7-d66279ea33b6]   Post Load (0.2ms)  SELECT "posts".* FROM "posts"
4[df88dbaa-50fd-4178-85d7-d66279ea33b6]   Rendered posts/index.html.erb within layouts/application (4.8ms)
5[df88dbaa-50fd-4178-85d7-d66279ea33b6] Completed 500 Internal Server Error in 10ms (ActiveRecord: 0.2ms)
6[df88dbaa-50fd-4178-85d7-d66279ea33b6]
7ActionView::Template::Error (divided by 0):
8    29: <br>
9    30:
10    31: <%= link_to 'New Post', new_post_path %>
11    32: <%= 1/0 %>
12  app/views/posts/index.html.erb:32:in `/'
13  app/views/posts/index.html.erb:32:in `_app_views_posts_index_html_erb___110320845380431566_70214104632140'
Copy

As we can see the request id tag is not prepended to the lines containing error details. If we search the log file by the request id then the error details would not be shown.

In Rails 5 errors in logs show log tags as well to overcome the problem we saw above.

Please note that the log tag name for request id has changed in Rails 5. The setting would thus look like as shown below.

1
2config.log_tags = [:request_id]
3
Copy

This is how the same log will look like in a Rails 5 application.

1
2[7efb4d18-8e55-4d51-b31e-119f49f5a410] Started GET "/" for ::1 at 2016-06-03 17:24:59 +0530
3[7efb4d18-8e55-4d51-b31e-119f49f5a410] Processing by PostsController#index as HTML
4[7efb4d18-8e55-4d51-b31e-119f49f5a410]   Rendering posts/index.html.erb within layouts/application
5[7efb4d18-8e55-4d51-b31e-119f49f5a410]   Post Load (0.9ms)  SELECT "posts".* FROM "posts"
6[7efb4d18-8e55-4d51-b31e-119f49f5a410]   Rendered posts/index.html.erb within layouts/application (13.2ms)
7[7efb4d18-8e55-4d51-b31e-119f49f5a410] Completed 500 Internal Server Error in 30ms (ActiveRecord: 0.9ms)
8[7efb4d18-8e55-4d51-b31e-119f49f5a410]
9[7efb4d18-8e55-4d51-b31e-119f49f5a410] ActionView::Template::Error (divided by 0):
10[7efb4d18-8e55-4d51-b31e-119f49f5a410]     29: <br>
11[7efb4d18-8e55-4d51-b31e-119f49f5a410]     30:
12[7efb4d18-8e55-4d51-b31e-119f49f5a410]     31: <%= link_to 'New Post', new_post_path %>
13[7efb4d18-8e55-4d51-b31e-119f49f5a410]     32: <%= 1/0 %>
14[7efb4d18-8e55-4d51-b31e-119f49f5a410]
15[7efb4d18-8e55-4d51-b31e-119f49f5a410] app/views/posts/index.html.erb:32:in `/'
16[7efb4d18-8e55-4d51-b31e-119f49f5a410] app/views/posts/index.html.erb:32:in `_app_views_posts_index_html_erb___1136362343261984150_70232665530320'
17
Copy