Еще одна статья про Rails и ELK

Есть много туториалов, которые рассказывают как хранить логи Rails приложения в ELK, большинство сводится либо к парсингу логов, либо сохранению краткой статистики запроса по UDP в logstash. В этой статье я бы хотел сосредоточиться на переносе абсолютно всех логов приложения в ELK по UDP.

Для примера поднимем Elastic stack локально через докер. Я воспользовался этим репозиторием. Перед началом нам нужно сказать logstash’у, что присылать мы ему будем json и чтобы он этот json преобразовал нам в список полей. Для этого откроем файл logstash/pipeline/logstash.conf и добавим в него следующие строки:

filter {   json {     source => "message"   } }

Затем командой docker-compose up мы развернем весь стек ELK. После того, как докер запустит контейнер, по адресу http://0.0.0.0:5601/ у нас будет доступна Kibana.

Продемонстрирую процесс интеграции с ELK на специально заготовленном стенде. Я попытался воссоздать небольшое, но реалистичное приложение, которое хранит данные в базе, имеет какое-то API, использует кеш на Redis’е, что-то обрабатывает в фоне и иногда ходит в другие сервисы по HTTP. Итак, начнем с самого начала.

Добавим несколько гемов

# Gemfile gem 'faraday' gem 'hiredis' gem 'httplog' gem 'logstash-event' gem 'logstash-logger', github: "motoroller95/logstash-logger" gem 'redis' gem 'sidekiq'

Расскажу про два основных гема: logstash-event и logstash-logger. Первый добавляет так называемый event, сущность, которая будет представлять одну запись (строчку лога), второй непосредственно сам логер. В процессе эксплуатации логера мной был найден дефект, который я исправил, но т.к. проект уже не поддерживается автором я подключил его из своего репозитория (на всякий случай pull-request висит). Так же тут присутствует еще один интересный гем httplog, который будет логировать все исходящие HTTP запросы. 

Для начала у нас есть небольшая модель

# app/models/post.rb class Post < ApplicationRecord   # create_table :posts do |t|   #   t.string :title   #   t.string :content   #   t.boolean :published, default: false, null: false   #   t.timestamps   # end end

Далее я добавил пару роутов

# routes.rb namespace :api do   resources :posts, except: :edit do     post :publish, on: :member   end   resources :external_services, only: %i[index show] end

Контроллеры

# app/controllers/api/external_services_controller.rb class Api::ExternalServicesController < ActionController::API   def index     response = Faraday.get('https://jsonplaceholder.typicode.com/posts')     render json: JSON.parse(response.body)   end    def show     response = Faraday.get("https://jsonplaceholder.typicode.com/posts/#{params[:id]}")     render json: JSON.parse(response.body)   end end  # app/controllers/api/posts_controller.rb class Api::PostsController < ActionController::API   before_action :find_post, only: %i[edit update destroy publish]   after_action :clear_cache, only: %i[update destroy]    def index     page = (params[:page] || 1).to_i - 1     posts = Rails.cache.fetch("posts:#{page}") do       Post.where(published: true).limit(20).offset(20 * page).as_json     end      render json: posts   end    def create     @post = Post.create!(post_params)     render json: @post   end    def show     render json: @post   end    def update     @post.update!(post_params)     render json: @post   end    def destroy     @post.destroy!     head :ok   end    def publish     PostPublishingJob.perform_later(@post.id)     head :ok   end  private   def find_post     @post = Post.find(params[:id])   end    def clear_cache     Rails.cache.clear   end    def post_params     params.permit(:title, :content)   end end

Сразу же покажу единственную background-job 

# app/jobs/post_publishing_job.rb class PostPublishingJob < ApplicationJob   def perform(post_id)     Post.find(post_id).update!(published: true)      Rails.cache.clear   end end

Теперь самое важное  -  настраиваем логи

# config/application.rb require_relative 'boot' require_relative '../lib/logging' require 'rails/all'  Bundler.require(*Rails.groups)  module App   class Application < Rails::Application     logger = LogStashLogger.new(       type: :udp,       host: '0.0.0.0',       port: 5000,       sync: true,       customize_event: ->(event) { Logging::EventTransformer::Server.call(event) }     )      config.logger = logger     config.active_job.queue_adapter = :sidekiq     config.log_tags = %i[uuid]     config.colorize_logging = false      HttpLog.configure do |config|       config.enabled = true       config.logger = logger     end      redis_config = { url: 'redis://127.0.0.1:6379/0', logger: logger }     config.cache_store = :redis_cache_store, redis_config   end end

А теперь по порядку. Первым делом создаем логер, которому говорим, что будем слать по UDP на 0.0.0.0 по 5000 порту. Я намеренно не стал использовать пакетную отправку логов и сделал sync = true и вот почему: по протоколу UDP мы можем отправить не более 65535 байт, что с одной стороны очень много, а с другой вызывает трудности. Если в один прекрасный момент приложение попытается записать большой кусок лога (стек-трейс к примеру) и выйдет за пределы 64кб, то мы потеряем все накопленные логи, т.к. отправка в logstash упадет с ошибкой. Конечно, есть опция max_message_size которой можно ограничить размер пакета, но в таком случае мы просто потеряем часть логов. Опция customize_event позволяет добавить дополнительные данные в лог. По сути мы создали логер, который мало чем отличается от обычного, разве что пишет не в файл, а в сеть.

Далее укажем Rails использовать наш новосозданный логер, а так же попросим логировать request_id, чтобы было удобно фильтровать запросы и выключим "разукрашивание" логов. Конфигурация HttpLog довольно простая и не нуждается в пояснениях. Финальным шагов настроим cache_store и попросим логировать все запросы к кешу.

Теперь про кастомизацию эвентов: LogstashLogger позволяет добавлять пользовательские данные к эвенту. У нас будет два типа данных, в зависимости от того в каком режиме запущено приложение: либо это сервер, либо sidekiq. В обоих случаях полезно будет логировать environment, в котором сейчас запущено приложение

# lib/event_transformer.rb class Logging::EventTransformer   def self.call(event)     event[:env] = Rails.env   end end

Затем в случае серверной части мы добавим такой код

class Logging::EventTransformer::Server < Logging::EventTransformer   def self.call(event)     super      event[:service] = 'server'     # Так же тут можно добавить что-нибудь более интересное, но поскольку это приложение очень      # маленькое обойдемся только сервисом. Для примера покажу как это можно сделать     # event[:user_id] = RequestStore[:user_id]     # event[:some_key] = some_value   end end 

Для sidekiq будет такой сетап

class Logging::EventTransformer::Sidekiq < Logging::EventTransformer   def self.call(event)     super      event[:service] = 'sidekiq'     # Воспользуемся тем фактом, что сайдкик устанавливает много полезной информации в      # локальном хранилище треда     Thread.current[:sidekiq_context]&.each { |k, v| event[k] = v }   end end

Однако, чтобы эвент трансформер сайдкика начал работать нужно произвести еще одну манипуляцию — сконфигурируем sidekiq-сервер:

Sidekiq.configure_server do |_config|   Rails.logger.formatter.instance_variable_set(     '@customize_event',     ->(event) { Logging::EventTransformer::Sidekiq.call(event) }   )    Sidekiq.logger = Rails.logger end

Тут как всегда есть два варианта: хороший, и по-простому. Я выбрал простой и немного покопавшись в исходниках LogstashLogger я нашел где он хранит блок кастомизации эвента и просто его переопределил. Если делать по хорошему, то нужно создать новый логер и настроить все библиотеки на его использование.

Собственно на этом вся настройка закончена, если немного поиграть с приложением, то можно будет увидеть логи в ELK:

Сервер:

и Sidekiq:

А так же эвент "в развертке":

На этом все, храните ваши логи удобно!