From f97d7388f5af7d42f9bbce939427e2c5e04bf6bc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Alberto=20Miedes=20Garc=C3=A9s?= Date: Fri, 4 Sep 2020 14:02:25 +0200 Subject: [PATCH] Add logger docs --- NEWS.md | 1 + doc/README.md | 3 +- doc/logging.md | 155 +++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 158 insertions(+), 1 deletion(-) create mode 100644 doc/logging.md diff --git a/NEWS.md b/NEWS.md index 182b6f594c..86d7c1dd9b 100644 --- a/NEWS.md +++ b/NEWS.md @@ -10,6 +10,7 @@ Development ### Bug fixes / enhancements * Bump cartodb-common to 0.3.4 [#15808](https://github.com/CartoDB/cartodb/pull/15808) * Fixes missing includes of LoggerHelper [#15812](https://github.com/CartoDB/cartodb/pull/15812) +* Adds logging docs [#15813](https://github.com/CartoDB/cartodb/pull/15813) 4.41.1 (2020-09-03) ------------------- diff --git a/doc/README.md b/doc/README.md index c20cfae2a1..7111d11062 100644 --- a/doc/README.md +++ b/doc/README.md @@ -5,6 +5,7 @@ Yes, there's a lot of docs missing, we appreciate [contributions](../CONTRIBUTIN - [API](api.md) - [redis](redis.md) - [Frontend](frontend/README.md) +- [Logging](logging.md) #### Developer Center @@ -12,4 +13,4 @@ The `developer-center` folder contains the public documentation for Auth API, Im The structure of folders replicates the section structure on the site. Guides, Support and Examples articles are written in markdown. Reference pages are documented using [Swagger](https://swagger.io/) (The following [Swagger editor]( https://swagger.io/tools/swagger-editor/) can be useful to test new content) -Changes of updates in this files are periodically fetched and updated in [Developer Center site](https://carto.com/developers/). Find some editing guidelines [here](https://github.com/CartoDB/developers/wiki/Editing-and-contributing-guidelines). \ No newline at end of file +Changes of updates in this files are periodically fetched and updated in [Developer Center site](https://carto.com/developers/). Find some editing guidelines [here](https://github.com/CartoDB/developers/wiki/Editing-and-contributing-guidelines). diff --git a/doc/logging.md b/doc/logging.md new file mode 100644 index 0000000000..b457f1c1d0 --- /dev/null +++ b/doc/logging.md @@ -0,0 +1,155 @@ +# Logging + +General guidelines to be applied project-wide are described in our [internal wiki](http://doc-internal.cartodb.net/platform/guidelines.html#structured-logging), while this page focuses on specific usage from the CartoDB application. + +## Important context + +Log messages are processed by our ELK stack. Each log message maps into a set of fields, which then are inserted in Elaticsearch. These fields have an associated type, which is automatically assigned by Elaticsearch when a new field name is received. + +This has the caveat that if a subsequent log message is received with the same field name but a different type (ex: 1 vs "1"), the log message is lost because the insertion in the Elasticsearch index fails. + +To mitigate this, **please review existing logging messages to check the format used** and existing logging conventions before writing new entries. + +## Logger structure + +The core of the logging sytem (`Carto::Common::Logger`) is in our shared code repository, [cartodb-common](https://github.com/CartoDB/cartodb-common). It contains modifications of the Rails standard logger: JSON formatting and additional attributes for the default logs. + +This repository wraps `Carto::Common::Logger` with a `::LoggerHelper` class, which adds some serialization logic and provides the following methods: + +```ruby +log_debug(message: 'Foo') +log_info(message: 'Foo') +log_warning(message: 'Foo') +log_error(message: 'Foo') # Reports to Rollbar +log_fatal(message: 'Foo') # Reports to Rollbar +``` + +## Guidelines + +**1. Avoid using very-generic names when naming log fields** + +If you do: + +```ruby +log_error(message: 'Foo', table: 'mytable') +``` + +This would prevent from someone afterwards doing the following: + +```ruby +log_error(message: 'Foo', table: { id: 123, name: 'mytable' }) +``` + +**2. Use nested attributes when possible** + +Use: + +```ruby +log_error(message: 'Foo', response: { code: '200', body: 'bar' }) +``` + +Instead of: + +```ruby +log_error(message: 'Foo', response_code: '200', response_body: 'bar') +``` + +**3. Reuse existing fields when possible** + +| Field name | Kibana field | Kibana type | Description | +| -------------- | --------------- | ----------- | ---------------- | +| `message` | `event_message` | String | Self-descriptive | +| `current_user` | `cdb-user` | String | Username performing (or affected by) the action | +| `target_user` | `target_user` | String | Username affected by the action. Use **only** when the actor of the action is not the same as the receiver | +| `organization` | `organization` | String | Name of the organization | +| `exception` | `exception` | Nested JSON | An `Exception` object | +| `error_detail` | `error_detail` | String | Additional error details | + +**4. Abstract common logger information** + +If the logging messages written in a class share a set of common fields, try to abstract it by defining a `log_context` method. + +For example: + +```ruby +module Carto + module Api + class GroupsController < ::Api::ApplicationController + + def create + # ... + rescue StandardError => e + log_error(exception: e) + head 500 + end + + def update + # ... + rescue StandardError => e + log_error(exception: e) + head 500 + end + + private + + def log_context + super.merge(group: @group, organization: @organization) + end + + end + end +end + +``` + +## Examples + +Logging the current user: + +```ruby +log_info(message: 'Foo', current_user: Carto::User.first) +log_info(message: 'Foo', current_user: User.first) +log_info(message: 'Foo', current_user: 'some-username') +# Serialized as: +# { 'event_message': 'Foo', 'cdb-user': 'some-username' } +``` + +Logging an action User A performed on User B: + +```ruby +log_info(message: 'Foo', current_user: user_a, target_user: user_b) +# Serialized as: +# { 'event_message': 'Foo', 'cdb-user': 'username-a', 'target_user': 'username-b' } +``` + +Logging organizations: + +```ruby +log_info(message: 'Foo', organization: Carto::Organization.first) +log_info(message: 'Foo', organization: Organization.first) +log_info(message: 'Foo', organization: 'organization-name') +# Serialized as: +# { 'event_message': 'Foo', 'organization': 'organization-name' } +``` + +Logging a captured exception: + +```ruby +log_error(message: 'Foo', exception: StandardError.new('My error')) +# Serialized as: +# { +# 'event_message': 'Foo', +# 'exception': { +# 'class': 'StandardError', +# 'message': 'My error', +# 'backtrace_hint': ['line_1', 'line_2', 'line_3'] +# } +# } +``` + +Logging a failed ActiveRecord validation: + +```ruby +invalid_user.save +log_warning(message: 'Unable to save user', current_user: invalid_user, error_detail: invalid_user.errors.full_messages.join(',')) +```