Migrate log traces to new Carto::Common::Logger

[amiedes]

Related: https://app.clubhouse.io/cartoteam/story/91596/migrate-log-traces-to-new-carto-logger

What does this PR do?

• Replaces traces using CartoDB::Logger per the new Carto::Common::Logger (wrapped by ::LoggerHelper)
• Avoids rescuing all types of exceptions in rescue blocks

Logging 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. I know this is not ideal, but solving it exceeds the scope of this PR.

Logging guidelines

1. Avoid using very-generic names when naming log fields

For example, if you do:

log_error(message: "Foo", table: "mytable")

This would prevent from someone afterwards doing the following:

log_error(message: "Foo", table: { id: 123, name: "mytable" })

2. Use nested attributes when possible

Use:

log_error(message: "Foo", response: { code: "200", body: "bar" })

Instead of:

log_error(message: "Foo", response_code: "200", response_body: "bar")

(!!) This is subject to future change or debate, but for the time being I opted for this approach.

3. Try to reuse existing fields when possible

This is a list of the more common ones:

• message - Self-descriptive. Maps to event_message in Kibana.
• current_user - Username of the user performing (or affected by) this action. Maps to cdb-user in Kibana. The LoggerHelper automatically serializes User and Carto::User objects received in this field to Carto::User#username.
• target_user - Use this field only when the action of the action is not the same as the affected user. For example, in the context of an organization admin deleting an organization user, the current_user would be the admin and the target_user the deleted user. The LoggerHelper automatically serializes User and Carto::User objects received in this field to Carto::User#username.
• organization - Name of the organization (if present). The LoggerHelper automatically serializes Organization and Carto::Organization objects received in this field to Carto::Organization#name.
• exception - An Exception object. It's automatically serialized by LoggerHelper
• error_detail - A string giving more details of an error. For example those present in user.errors.full_messages after running ActiveRecord valiations.

4. Be conservative about logged in formation

• Logging confidential attributes might conflict with GDPR guidelines
• Logging too many fields has performance implications in Kibana

5. Try to 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:

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

Suggestions for future work

• Remove leftovers of very legacy logger in config/initializers/error_notifier.rb
• Delegate to each model what attributes are serialized to the log, instead of having to write them explicitly. Ideally create a set of presenters / serializers, in a similar fashion we do when serializing JSON objects for an API
• Solve issues with Kibana field conflicts and performance
• Move ResqueFailureLogger to Carto::Common::JobLogger

[rafatower]

Nice job with log_context. Nice distinction between current_user and target_user.

So good the file lib/cartodb/logger.rb is deleted.

I think the only change needed is to rollback the deletion of remaining_days_deletion

[rafatower]

A bit off-topic: this coming from central, and the same way we add extra info for oauth errors, we may eventually want to add extra info about the error (but perhaps this is not the right place for it).

[amiedes]

@rafatower thanks for the suggestions 🙂 . I've applied some of them in the last commit.

Tomorrow I'll test this in staging.

[thedae]

Awesome job :)