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

[Kate]

Есть много туториалов, которые рассказывают как хранить логи 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 osts do |t|
# t.string :title
# t.string :content
# t.boolean ublished, default: false, null: false
# t.timestamps
# end
end

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


# routes.rb
namespace :api do
resources osts, except: :edit do
post ublish, 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:ostsController < ActionController::API
before_action :find_post, only: %i[edit update destroy publish]
after_action :clear_cache, only: %i[update destroy]

def index
page = (params[age] || 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 k
end

def publish
PostPublishingJob.perform_later(@post.id)
head k
end

private
def find_post
@post = Post.find(params[:id])
end

def clear_cache
Rails.cache.clear
end

def post_params
params.permittitle, :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:

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

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

Источник статьи: https://habr.com/ru/post/506954/