🌲 Timber - Log Better. Solve Problems Faster.

ISC License Hex.pm Documentation Build Status

Overview

Timber for Ruby is a drop in replacement for your logger. It takes a different approach to structured logging. Instead of parsing, which relies on non-standard, unreadable, hard to use text logs, Timber integrates directly with your application, augmenting your logs with rich metadata and context. It automatically transforms your logs into rich events, fundamentally changing the way you use your logs.

  1. Easy setup - mix timber.install
  2. Seamlessly integrates with popular libraries and frameworks
  3. Modern fast console, designed specifically for your application

Installation

  1. In your Gemfile, add the timber gem:

    gem 'timber', '~> 2.1'
    
  2. In your shell, run bundle install

  3. In your shell, run bundle exec timber install

Usage

Basic logging

Use the `Timber::Logger` just like you would `::Logger`: ```ruby logger.info("My log message") # use warn, error, debug, etc. # => My log message @metadata "info", "context": {...} ``` ---

Custom events

Custom events allow you to extend beyond events already defined in the [`Timber::Events`](lib/timber/events) namespace. ```ruby logger.warn "Payment rejected", payment_rejected: "abcd1234", amount: 100, reason: "Card expired" # => Payment rejected @metadata "warn", "event": {"payment_rejected": {"customer_id": "abcd1234", "amount": 100, "reason": "Card expired"}, "context": ...} ``` * Notice the `:payment_rejected` root key. Timber will classify this event as such. * In the [Timber console](https://app.timber.io) use the query: `type:payment_rejected` or `payment_rejected.amount:>100`. * See more details on our [custom events docs page](https://timber.io/docs/ruby/usage/custom-events/) ---

Custom contexts

Context is additional data shared across log lines. Think of it like log join data. This is how a query like `context.user.id:1` can show you all logs generated by that user. Custom contexts allow you to extend beyond contexts already defined in the [`Timber::Contexts`](lib/timber/contexts) namespace. ```ruby logger.with_context(build: "1.0.0") do logger.info("My log message") end # => My log message @metadata "info", "context": {"build": {"version": "1.0.0"}} ``` * Notice the `:build` root key. Timber will classify this context as such. * In the [Timber console](https://app.timber.io) use queries like: `build.version:1.0.0` * See more details on our [custom contexts docs page](https://timber.io/docs/ruby/usage/custom-contexts/) ---

Metrics & Timings

Aggregates destroy details, and with Timber capturing metrics and timings is just logging events. Timber is built on modern big-data principles, it can calculate aggregates across terrabytes of data in seconds. Don't reduce the quality of your log data to accomodate a restrive logging system. Here's a timing example. Notice how Timber automatically calculates the time and adds the timing to the message. ```ruby timer = Timber::Timer.start # ... code to time ... logger.info("Processed background job", background_job: timer) # => Processed background job in 54.2ms @metadata "info", "event": {"background_job": {"time_ms": 54.2}} ``` And of course, `time_ms` can also take a `Float` or `Fixnum`: ```ruby logger.info("Processed background job", background_job: 45.6) ``` Lastly, metrics aren't limited to timings. You can capture any metric you want: ```ruby logger.info("Credit card charged", credit_card_charge: 123.23) # => Credit card charged @metadata "info", "event": {"credit_card_charge": {"amount": 123.23}} ``` In Timber you can easily sum, average, min, and max the `amount` attribute across any interval you desire.

Configuration

Below are a few popular configuration options, for a comprehensive list, see Timber::Config.

Logrageify. Silence noisy logs (sql query, template renders)

Timber allows you to silence noisy logs that aren't of value to you, just like [lograge](https://github.com/roidrage/lograge). In fact, we've provided a convenience method for anyone transitioning from lograge: ```ruby # config/initializers/timber.rb config = Timber::Config.instance config.logrageify!() ``` It turns this: ``` Started GET "/" for 127.0.0.1 at 2012-03-10 14:28:14 +0100 Processing by HomeController#index as HTML Rendered text template within layouts/application (0.0ms) Rendered layouts/_assets.html.erb (2.0ms) Rendered layouts/_top.html.erb (2.6ms) Rendered layouts/_about.html.erb (0.3ms) Rendered layouts/_google_analytics.html.erb (0.4ms) Completed 200 OK in 79ms (Views: 78.8ms | ActiveRecord: 0.0ms) ``` Into this: ``` Get "/" sent 200 OK in 79ms @metadata ... ``` Internally this is equivalent to: ```ruby # config/initializers/timber.rb config = Timber::Config.instance config.integrations.action_controller.silence = true config.integrations.action_view.silence = true config.integrations.active_record.silence = true config.integrations.rack.http_events.collapse_into_single_event = true ``` Feel free to deviate and customize which logs you silence. We recommend a slight deviation from lograge with the following settings: ```ruby # config/initializers/timber.rb config = Timber::Config.instance config.integrations.action_view.silence = true config.integrations.active_record.silence = true config.integrations.rack.http_events.collapse_into_single_event = true ``` This does _not_ silence the controller call log event. This is because Timber captures the parameters passed to the controller, which are generally valuable when debugging. For a full list of integration settings, see [Timber::Config::Integrations](http://www.rubydoc.info/github/timberio/timber-ruby/Timber/Config/Integrations) ---

Silence specific requests (LB health checks, etc)

The following will silence all `[GET] /_health` requests: ```ruby # config/initializers/timber.rb config = Timber::Config.instance config.integrations.rack.http_events.silence_request = lambda do |rack_env, rack_request| rack_request.path == "/_health" end ``` We require a block because it gives you complete control over how you want to silence requests. The first parameter being the traditional Rack env hash, the second being a [Rack Request](http://www.rubydoc.info/gems/rack/Rack/Request) object. ---

Change log formats

Simply set the formatter like you would with any other logger: ```ruby # This is set in your various environment files logger.formatter = Timber::Logger::JSONFormatter.new ``` Your options are: 1. [`Timber::Logger::AugmentedFormatter`](http://www.rubydoc.info/github/timberio/timber-ruby/Timber/Logger/AugmentedFormatter) - (default) A human readable format that _appends_ metadata to the original log line. The Timber service can parse this data appropriately. Ex: `My log message @metadata "level":"info","dt":"2017-01-01T01:02:23"level":"info","dt":"2017-01-01T01:02:23.234321Z"` 2. [`Timber::Logger::JSONFormatter`](http://www.rubydoc.info/github/timberio/timber-ruby/Timber/Logger/JSONFormatter) - Ex: `log message","dt":"2017-01-01T01:02:23.234321Z"` 3. [`Timber::Logger::MessageOnlyFormatter`](http://www.rubydoc.info/github/timberio/timber-ruby/Timber/Logger/MessageOnlyFormatter) - For use in development / test. Prints logs as strings with no metadata attached. Ex: `My log message` ---

Capture custom user context

By default Timber automatically captures user context for most of the popular authentication libraries (Devise, Omniauth, and Clearance). See [Timber::Integrations::Rack::UserContext](http://www.rubydoc.info/github/timberio/timber-ruby/Timber/Integrations/Rack/UserContext) for a complete list. In cases where you Timber doesn't support your strategy, or you want to customize it further, you can do so like: ```ruby # config/initializers/timber.rb config = Timber::Config.instance config.integrations.rack.user_context.custom_user_hash = lambda do |rack_env| user = rack_env['warden'].user if user { id: user.id, # unique identifier for the user, can be an integer or string, name: user.name, # identifiable name for the user, email: user.email, # user's email address } else nil end end ``` *All* of the user hash keys are optional, but you must provide at least one. ---

Capture release / deploy context

[Timber::Contexts::Release](http://www.rubydoc.info/github/timberio/timber-ruby/Timber/Contexts/Release) tracks the current application release and version. If you're on Heroku, simply enable the [dyno metadata](https://devcenter.heroku.com/articles/dyno-metadata) feature. If you are not, set the following environment variables and this context will be added automatically: 1. `RELEASE_COMMIT` - Ex: `2c3a0b24069af49b3de35b8e8c26765c1dba9ff0` 2. `RELEASE_CREATED_AT` - Ex: `2015-04-02T18:00:42Z` 3. `RELEASE_VERSION` - Ex: `v2.3.1` All variables are optional, but at least one must be present. ---

Jibber-Jabber

Which log events does Timber structure for me?

Out of the box you get everything in the [`Timber.Events`](lib/timber/events) namespace. We also add context to every log, everything in the [`Timber.Contexts`](lib/timber/contexts) namespace. Context is structured data representing the current environment when the log line was written. It is included in every log line. Think of it like join data for your logs. ---

What about my current log statements?

They'll continue to work as expected. Timber adheres strictly to the default `Logger` interface and will never deviate in *any* way. In fact, traditional log statements for non-meaningful events, debug statements, etc, are encouraged. In cases where the data is meaningful, consider [logging a custom event](#usage).

When to use metadata or events?

At it's basic level, both metadata and events serve the same purpose: they add structured data to your logs. And anyone that's implemented structured logging know's this can quickly get out of hand. This is why we created events. Here's how we recommend using them: 1. Use `events` when the log cleanly maps to an event that you'd like to alert on, graph, or use in a meaningful way. Typically something that is core to your business or application. 2. Use metadata for debugging purposes; when you simply want additional insight without polluting the message. ### Example 1: Logging that a payment was rejected This is clearly an event that is meaningful to your business. You'll probably want to alert and graph this data. So let's log it as an official event: ```ruby logger.info("Payment rejected", payment_rejected: "xiaus1934", amount: 1900, currency: "USD") ``` ### Example 2: Logging that an email was changed This is definitely log worthy, but not something that is core to your business or application. Instead of an event, use metadata: ```ruby logger.info("Email successfully changed", old_email: old_email, new_email: new_email) ``` ---

The Timber Console

Timber Console

Your Moment of Zen