This gem is heavily inspired from lograge, but it's focused on one thing and one thing only. That's making your logs awesome like this:
How it's done ?
By, using these awesome tools:
- Logstash - Store and index your logs
- Kibana - for awesome visualization. This is optional though, and you can use any other visualizer
Update: Logstash now includes Kibana build in, so no need to separately install. Logstasher has been tested with logstash version 1.4.2 with file input and json codec.
See quickstart for quickly setting up logstash
This gem purely focuses on how to generate logstash compatible logs i.e. logstash json event format, without any overhead. Infact, logstasher logs to a separate log file named logstash_<environment>.log.
The reason for this separation:
- To have a pure json log file
- Prevent any logger messages(e.g. info) getting into our pure json logs
Before logstasher :
Started GET "/login" for 10.109.10.135 at 2013-04-30 08:59:01 -0400
Processing by SessionsController#new as HTML
[ActiveJob] [TestJob] [61d6e87a-875d-4255-9424-cab7d5ff208c] Performing TestJob from Test(default) with arguments: 0, 1
Rendered sessions/new.html.haml within layouts/application (4.3ms)
Rendered shared/_javascript.html.haml (0.6ms)
Rendered shared/_flashes.html.haml (0.2ms)
Rendered shared/_header.html.haml (52.9ms)
Rendered shared/_title.html.haml (0.2ms)
Rendered shared/_footer.html.haml (0.2ms)
Completed 200 OK in 532ms (Views: 62.4ms | ActiveRecord: 0.0ms | ND API: 0.0ms)
After logstasher:
{"job_id":"61d6e87a-875d-4255-9424-cab7d5ff208c","queue_name":"Test(default)","job_class":"ExampleJob","job_args":[1,0],
"exception":["ZeroDivisionError","divided by 0"],"duration":3.07,"request_id":"61d6e87a-875d-4255-9424-cab7d5ff208c",
"source":"unknown","tags":["job","perform","exception"],"@timestamp":"2016-03-29T16:14:32.837Z","@version":"1"}
{"@source":"unknown","@tags":["request"],"@fields":{"method":"GET","path":"/","format":"html","controller":"file_servers"
,"action":"index","status":200,"duration":28.34,"view":25.96,"db":0.88,"ip":"127.0.0.1","route":"file_servers#index",
"parameters":"","ndapi_time":null,"uuid":"e81ecd178ed3b591099f4d489760dfb6","user":"shadab_ahmed@abc.com",
"site":"internal"},"@timestamp":"2013-04-30T13:00:46.354500+00:00"}
By default, the older format rails request logs are disabled, though you can enable them.
In your Gemfile:
gem 'logstasher'
# Enable the logstasher logs for the current environment
config.logstasher.enabled = true
# Each of the following lines are optional. If you want to selectively disable log subscribers.
config.logstasher.controller_enabled = false
config.logstasher.mailer_enabled = false
config.logstasher.record_enabled = false
config.logstasher.view_enabled = false
config.logstasher.job_enabled = false
# This line is optional if you do not want to suppress app logs in your <environment>.log
config.logstasher.suppress_app_log = false
# This line is optional, it allows you to set a custom value for the @source field of the log event
config.logstasher.source = 'your.arbitrary.source'
# This line is optional if you do not want to log the backtrace of exceptions
config.logstasher.backtrace = false
# This line is optional, defaults to log/logstasher_<environment>.log
config.logstasher.logger_path = 'log/logstasher.log'
Has the same optional fields as the <environment>.rb. You can specify common configurations that are then overriden by environment specific configurations:
controller_enabled: true
mailer_enabled: false
record_enabled: false
job_enabled: false
view_enabled: true
suppress_app_log: false
development:
enabled: true
record_enabled: true
production:
enabled: true
mailer_enabled: true
view_enabled: false
Logstasher can be configured to log the contents of the params hash. When enabled, the contents of the params hash (minus the ActionController internal params) will be added to the log as a deep hash. This can cause conflicts within the Elasticsearch mappings though, so should be enabled with care. Conflicts will occur if different actions (or even different applications logging to the same Elasticsearch cluster) use the same params key, but with a different data type (e.g. a string vs. a hash). This can lead to lost log entries. Enabling this can also significantly increase the size of the Elasticsearch indexes.
To enable this, add the following to your <environment>.rb
# Enable logging of controller params
config.logstasher.log_controller_parameters = true
Since some fields are very specific to your application for e.g. user_name, so it is left upto you, to add them. Here's how to add those fields to the logs:
# Create a file - config/initializers/logstasher.rb
if LogStasher.enabled?
LogStasher.add_custom_fields do |fields|
# This block is run in application_controller context,
# so you have access to all controller methods
fields[:user] = current_user && current_user.mail
fields[:site] = request.path =~ /^\/api/ ? 'api' : 'user'
# If you are using custom instrumentation, just add it to logstasher custom fields
LogStasher.custom_fields << :myapi_runtime
end
end
Logstasher can easily log messages from ActionMailer, such as incoming/outgoing e-mails and e-mail content generation (Rails >= 4.1).
This functionality is automatically enabled. Since the relationship between a concrete HTTP request and a mailer invocation is lost
once in an ActionMailer instance method, global (per-request) state is kept to correlate HTTP requests and events from other parts
of rails, such as ActionMailer. Every time a request is invoked, a request_id key is added which is present on every ActionMailer event.
Note: Since mailers are executed within the lifetime of a request, they will show up in logs prior to the actual request.
Logstasher can also easily log messages from ActiveJob (Rails >= 4.2).
This functionality is automatically enabled. The request_id is set to the Job ID when the job is
performed, and then reverted back to its previous value once the job is complete. Imagine this
scenario:
- Web request starts (sets
request_idto some value) - Job is enqueued because of the web request (the same web
request_idis used) - Job is performing starts (pretend non-asynchronous adapter or perform_now was used)
request_idis set to the job id. This is important because for asynchronous jobs, there's no way to remember the originalrequest_id- Now, you can add your own detailed logging to the job, and the
request_idcan be used - Once the job completes, the
request_idis reverted and other SQL and View log lines will use that same oldrequest_idagain.
It is possible to listen to any ActiveSupport::Notifications events and store arbitrary data to be included in the final JSON log entry:
# In config/initializers/logstasher.rb
# Watch calls the block with the same arguments than any ActiveSupport::Notification, plus a store
LogStasher.watch('some.activesupport.notification') do |name, start, finish, id, payload, store|
# Do something
store[:count] = 42
end
Would change the log entry to:
{"@source":"unknown","@tags":["request"],"@fields":{"method":"GET","path":"/","format":"html","controller":"file_servers","action":"index","status":200,"duration":28.34,"view":25.96,"db":0.88,"ip":"127.0.0.1","route":"file_servers#index", "parameters":"","ndapi_time":null,"uuid":"e81ecd178ed3b591099f4d489760dfb6","user":"shadab_ahmed@abc.com", "site":"internal","some.activesupport.notification":{"count":42}},"@timestamp":"2013-04-30T13:00:46.354500+00:00"}
The store exposed to the blocked passed to watch is thread-safe, and reset after each request.
By default, the store is only shared between occurences of the same event.
You can easily share the same store between different types of notifications, by assigning them to the same event group:
# In config/initializers/logstasher.rb
LogStasher.watch('foo.notification', event_group: 'notification') do |*args, store|
# Shared store with 'bar.notification'
end
LogStasher.watch('bar.notification', event_group: 'notification') do |*args, store|
# Shared store with 'foo.notification'
end
Follow the instructions at logstash documentation to setup logstash. Start logstash with the following command:
bin/logstash -f quickstart.conf
All versions require Rails 3.0.x and higher and Ruby 1.9.2+. Tested on Rails 4 and Ruby 2.0
- Run tests -
rake - Generate test coverage report -
rake coverage. Coverage report path - coverage/index.html
Copyright (c) 2016 Shadab Ahmed, released under the MIT license