Сервис для логирования ошибок

Всем разработчикам известна ситуация, когда приложение заглючило и пользователь не может сделать то, что ему нужно. Причины разные: пользователь ввёл неправильные данные, у него медленный интернет и многое другое. Без системы логирования разобрать эти ошибки сложно, а порой невозможно. С другой стороны, система логирования — хороший индикатор проблемных мест в работе системы. Я расскажу, как построить систему логирования в своём проекте (да, ещё раз). В статье расскажу об Elasticsearch + Logstash + Kibana и Prometheus и как их заинтегрировать со своим приложением.

2ГИС — это веб-карта и справочник организаций. У фирмы может быть дополнительный контент — фотографии, скидки, логотип и прочее. И чтобы владельцам бизнеса было удобно управлять этим добром, был создан Личный кабинет. С помощью Личного кабинета можно:

• Добавлять или изменять контакты организации
• Загружать фотографии, логотип
• Смотреть, что делают пользователи при открытии организации и многое другое.

Личный кабинет состоит из двух проектов: бэкенд и фронтенд. Бэкенд написан на PHP версии 5.6, используется фреймворк Yii 1 (да, да). Активно используем Сomposer для управления зависимостями в проекте, автозагрузку классов в соответствии PSR-4, namespace, trait. В будущем планируем обновлять версию PHP до семёрки. В качестве веб-сервера используем Nginx, данные храним в MongoDB и PostgreSQL. Фронтенд написан на JavaScript, используем фреймворк нашего приготовления Catbee. Бэкенд предоставляет API для фронтенда. Далее в докладе буду говорить исключительно про бэкенд.

Вот схема наших интеграций. Нам это напоминает звёздное небо. Если приглядеться, можно увидеть Большую медведицу:

Внешние сервисы разнородные — разрабатываются дюжиной команд, со своим стеком технологий и API. Сценарии интеграции получаются нетривиальными — сначала ходим в один сервис, получаем данные, накладываем свою бизнес-логику, идём ещё в несколько сервисов с новыми данным, объединяем ответы и отдаём результат на фронтенд. И если у пользователя возникает проблема и он не может осуществить желаемое, например, продлить рекламную кампанию, то без системы логирования нам не понять, где была проблема — либо неправильно отправляем данные во внешний сервис, либо неправильно интерпретируем ответ, либо внешний сервис недоступен, либо неправильно накладываем свою бизнес-логику.

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

• Нужно больше контекста об ошибках — что произошло и у какого пользователя.
• Собирать входящие запросы в удобном виде.
• Если методы долго отвечают, то нужно уведомить команду об этом.

Логирование ошибок

Исторически сложилось, что в нашей компании для сбора и просмотра логов используется стэк технологий Elasticsearch + Logstash + Kibana, сокращённо ELK. Elasticsearch — NoSQL-хранилище документов, с возможностью полнотекстового поиска. Logstash настроен на приём логов по TCP/UDP-протоколам, читает сообщения из Redis и сохраняет в Elasticsearch. Kibana предоставляет визуальный интерфейс для поиска и отображения собранных данных.

Если у клиента идёт что-то не так, то он обращается в техподдержку из своего аккаунта с описанием проблемы. У нас было логирование ошибок, но не было ни email пользователя, ни вызванного API-метода, ни стэка вызова. В сообщениях была лишь строка из необработанного Exception вида «Запрос вернул некорректный результат». Из-за этого мы искали проблему по времени обращения клиента и ключевым словам, что не всегда было точно — клиент мог обратиться через день, и помочь было очень сложно.

Помучавшись, мы решили, что надо что-то делать и добавили необходимую информацию — email пользователя, API-метод, тело запроса, стэк вызова и наши контроллер и экшен, которые обрабатывали запрос. В итоге мы упростили жизнь техподдержке и себе — ребята нам скидывают email пользователя, а мы по нему находим записи в логах и разбираемся с проблемой. Мы точно знаем, у какого пользователя была проблема, какой метод был вызван и какая часть нашего кода обработала его. Никаких сравнений по времени обращения!

Сообщения об ошибках отправляем во время работы приложения по протоколу UDP в формате Graylog Extended Log Format, или сокращенно GELF. Формат хорош тем, что сообщения могут быть сжаты популярными алгоритмами и разделены на части, тем самым снижая объем передаваемого трафика из нашего приложения в Logstash. Протокол UDP пусть и не гарантирует доставку сообщений, но накладывает минимум накладных расходов на время ответа, поэтому такой вариант нас устраивает. В приложении используем библиотеку gelf-php, которая предоставляет возможности по отправке логов в разных форматах и протоколах. Рекомендую использовать её в своих PHP-приложениях.

Вывод — если ваше приложение работает с внешними пользователями и вам нужно искать ответы на возникающие вопросы техподдержки, смело добавляйте информацию, которая поможет идентифицировать клиента и его действия.
Пример нашего сообщения:

{
    "user_email": "test@test.ru",
    "api_method": "orgs/124345/edit",
    "method_type": "POST",
    "payload": "{'name': 'Новое название'}",
    "controller": "branches/update",
    "message": "Undefined index: 'name'
File: /var/www/protected/controllers/BranchesController.php
Line: 50"
}

Логирование запросов

Логирования запросов в структурированном виде и сбор статистики отсутствовали, поэтому было непонятно, какие методы чаще всего вызываются и сколько по времени отвечают. Это привело к тому, что мы не могли:

• оценить допустимое время ответа методов.
• причину возникновения тормозов — на нашей стороне или на стороне внешнего сервиса (помните схему со звёздным небом?)
• как можно оптимизировать наш код, чтобы уменьшить время ответа.

В рамках данной задачи нам предстояло решить вопросы:

1. выбор параметров ответа для логирования
2. отправка параметров в Logstash

Мы используем веб-сервер Nginx, и он умеет писать access-логи в файл. Для решения первой задачи указали новый формат сохранения логов в конфигурации:

log_format main_logstash
'{'
    '"time_local": "$time_local",'
    '"request_method": "$request_method",'
    '"request_uri": "$request_uri",'
     '"request_time": "$request_time",'
     '"upstream_response_time": "$upstream_response_time",'
     '"status": "$status",'
    '"request_id": "$request_id"'
'}';
server {
    access_log /var/log/nginx/access.log main_logstash;
}

Большинство метрик, думаю, вопросов не вызывает, расскажу подробнее про наиболее интересную — $request_id. Это уникальный идентификатор, UUID версии 4, который генерируется Nginx для каждого запроса. Данный заголовок мы пробрасываем в запросе во внешние сервисы и можем отследить ответ запроса в логах других сервисах. Очень удобно при поиске проблем в других сервисах — никаких сравнений по времени, урлу вызванного метода.

Для отправки логов в Logstash используем утилиту Beaver. Устанавливается на все ноды приложения, с которых планируется отправка логов. В конфигурации указывается файл, который будет парситься для получения новых логов, указываются поля, которые будут отправляться с каждым сообщением. Сообщения отправляются в Redis-кластер, из которого Logstash забирает данные. Вот наша конфигурация Beaver:

[/var/log/nginx/access.log]
    type: nginx_accesslog
    add_field: team,lk,project,backend
    tags: nginx_json

По полям type и tags в Logstash по нашим значениям сделана фильтрация и обработка логов, у вас эти значения могут быть свои. Кроме того, добавляем поля team и project, чтобы можно было идентифицировать команду и проект, которым принадлежат логи.

Научившись собирать access-логи, мы перешли к определению SLA методов. SLA, договор на уровень оказания услуг, в нашем случае мы гарантируем, что 95-ый перцентиль по времени ответа методов будет не более 0.4 секунд. Если не укладываемся в допустимое время, то значит, что в приложении либо одна из интеграций тормозит и обращаемся к связанной команде, либо что-то не так в нашем коде и необходима оптимизация.

Вывод по сбору access-логов — мы определили наиболее часто вызываемые методы и их допустимое время ответа.

Вот примеры наших отчётов на одном из измеряемых методов. Первый — чему равны 50, 95 и 99 перцентили времени ответа и среднее время ответа:

Диаграмма статусов ответа:

Среднее время ответа за промежуток времени:

Оповещения команды о падении SLA

После сбора логов нам пришла идея, что нужно оперативно узнавать о падении скорости. Постоянно держать открытым браузер с Kibana, нажимать F5, сравнивать в уме текущее значение 95-ого перцентиля с допустимым оказалось не очень практично — есть много других интересных задач в проекте. Поэтому для формирования оповещений мы добавили интеграцию с системой Prometheus. Prometheus — это система с открытым исходным кодом для сбора, хранения и анализа метрик работающего приложения. Официальный сайт с документацией.

Нам система понравилась тем, что в случае срабатывания триггера можно отправить оповещение на почту. Возможность предоставляется из коробки, без заморочек с доступами к серверам и без написания кастомных скриптов для формирования оповещения. Система написана на языке Go, создатели — компания SoundCloud. Существуют библиотеки для сбора метрик на разными языками — Go, PHP, Python, Lua, C#, Erlang, Haskell и другие.

Я не буду рассказывать, как установить и запустить Prometheus. Если вам интересно это, предлагаю почитать статью. Я сделаю упор на тех моментах, которые имели практическое значение для нас.

Схема интеграции выглядит так — клиентское приложение по адресу отдаёт набор метрик, Prometheus заходит на данный адрес, забирает и сохраняет метрики в своём хранилище.

Давайте разберёмся, как выглядят метрики.

1. Название — это идентификатор изучаемой характеристики. Например, количество входящих запросов.
2. У метрики в момент времени есть определённое значение. Время проставляет Prometheus при сборе метрик.
3. У метрики могут быть лейблы. Они содержат дополнительную информацию о собранном числе. В примере указана нода приложения и API-метод. Основная фишка лейблов в том, что по ним можно осуществлять поиск и делать необходимые выборки данных.

Хранилища данных формата «время — значение» называются Базами данных временных рядов. Это узкоспециализированные NoSQL-хранилище для хранения изменяющихся во времени показателей. Например, количество пользователей на сайте в 10 часов утра, за день, за неделю и так далее. Из-за особенностей решаемых задач и способа хранения такие БД обеспечивают высокую производительность и компактное хранение данных.

Prometheus поддерживает несколько типов метрик. Рассмотрим первый тип, называется Счётчик. Значение Счётчика при новых измерениях всегда растёт вверх. Идеально подходит для измерения общего количества входящих запросов за всю историю — не может быть такого, чтобы сегодня было 100 суммарно запросов, а завтра количество уменьшилось до 80.

Но как быть с измерением времени ответа? Оно не обязательно растёт вверх, более того, может упасть вниз, быть какое-то время на одном уровне, а потом вырасти вверх. Изменение может произойти менее чем за 10 секунд, и нам хочется видеть динамику изменения времени ответа для каждого запроса. К счастью, есть тип Гистограмма. Для формирования необходимо определить интервал измерения времени ответа. В примере возьмём от 0.1 до 0.5 секунды, всё что больше будем считать как Бесконечность.

Вот как выглядит начальное состояние Гистограммы:

api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.1"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.2"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.3"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.4"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.5"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="+Inf"} 0

api_request_time_sum{node="api1.2gis.com",handler="/users"} 0
api_request_time_count{node="api1.2gis.com",handler="/users"} 0

На каждое значение из интервала мы создаём Счётчик по определённым правилам:

1. В названии обязательно должен быть постфикс _bucket
2. Должен быть лейбл le, в котором указывается значение из интервала. Плюс должен быть Счётчик со значением +Inf.
3. Должны быть Счётчики с постфиксом _sum и _count. В них сохраняется суммарное общее время всех ответов и количество запросов. Нужны для удобного подсчёта 95-ого перцентиля средствами Prometheus.

Давайте разберёмся, как правильно заполнять Гистограмму временем ответа. Для этого нужно найти серии, у которых значение лейбла le больше либо равно времени ответа, и их увеличить на единицу. Предположим, что наш метод ответил за 0.4 секунды. Мы находим те Счётчики, у которых лейбл le больше либо равен 0.4, и к значению добавляем единицу:

api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.1"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.2"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.3"} 0
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.4"} 1
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="0.5"} 1
api_request_time_bucket{node="api1.2gis.com",handler="/users",le="+Inf"} 1

api_request_time_sum{node="api1.2gis.com",handler="/users"} 0.4
api_request_time_count{node="api1.2gis.com",handler="/users"} 1

Если метод отвечает за 0.1 секунду, то мы увеличиваем все серии. Если отвечает за 0.6 секунд, то увеличиваем лишь счётчик со значением «+Inf». Не забываем увеличивать счётчики api_request_time_sum и api_request_time_count. С помощью Гистограммы можно измерять время ответа, которое за короткий промежуток может часто меняться.

Prometheus поддерживает ещё два типа метрик — Шкала и Сводка результатов. Шкала описывает характеристику, значение которой может как увеличиваться, так и уменьшаться. В задачах не используем, так как такие показатели у нас не измеряются. Сводка результатов — это расширенная Гистограмма, которая сохраняет вычисляемые на стороне приложения квантили. Теоретически можно было бы рассчитывать 95-процентный перцентиль, или 0.95 квантиль, но это добавило бы кода по подсчёту на клиентской стороне и лишило бы гибкости в отчётах — могли бы использовать только вычисленные нами квантили. Поэтому свой выбор остановили на Гистограмме.

Формирование Гистограммы мы реализовали в Nginx на языке Lua. Нашли готовый проект на GitHub, который подключается в конфигурации Nginx и формирует Гистограмму описанным выше способом. Собирать данные нам необходимо с наиболее часто вызываемых методов, которые, как вы помните, мы определили после отправки access-логов в Logstash. Поэтому потребовалось добавить бизнес-логики по проверке, нужно запрос логировать или нет.

В итоге интеграция заняла неделю, вместе с изучением матчасти Prometheus и основ языка Lua. На наш взгляд, это отличный результат. Ещё очень здорово, что на время ответа добавляется незначительный, порядка 5-10 мс, оверхеад из-за формирования Гистограмм и проверки нашей бизнес-логики, что меньше, чем предполагали.

Но есть и минусы у этого решения — не учитываем время запросов, у которых статус не 200. Причина — директива log_by_lua, в которую мы добавили логирование, в таком случае не вызывается. Вот подтверждение. С другой стороны, нам время ответа таких запросов неинтересно, потому что это ошибка. Ещё один минус — Гистограмма хранится в shared-памяти Nginx. При перезапуске Nginx память очищается, и собранные метрики теряются. С этим тоже можно жить — перезапускать Nginx командой reload, и настроить Prometheus, чтобы он чаще забирал метрики.

Вот конфигурация Nginx для создания Гистограммы:

lua_shared_dict prometheus_metrics 10M;

init_by_lua '
    prometheus = require("prometheus").init("prometheus_metrics")
    prometheusHelper = require("prometheus_helper")
    metric_request_time = prometheus:histogram("nginx_http_request_time", {"api_method_end_point", "request_method"})
'

Здесь мы выделяем общую память, подключаем библиотеку и хэлпер с нашей бизнес-логикой и инициализируем Гистограмму — присваиваем имя и лейблы.

За логирование запроса отвечает данная конфигурация:

location / {
    log_by_lua '
        api_method_end_point = prometheusHelper.convert_request_uri_to_api_method_end_point(ngx.var.request_uri, ngx.var.request_method)
        if (api_method_end_point ~= nil) then
            metric_request_time:observe(tonumber(ngx.var.request_time),{api_method_end_point, ngx.var.request_method})
    '
}

Здесь мы в директиве log_by_lua проверяем, нужно ли логировать запрос, и если да, то добавляем его время ответа в Гистограмму.

Метрики отдаются через Nginx по endpoint:

server {
    listen 9099;
    server_name api1.2gis.com;
    location /metrics {
        content_by_lua 'prometheus:collect()';
    }
}

Теперь нужно в конфигурации Prometheus указать ноды нашего приложения для сбора метрик:

  - targets:
      - api1.2gis.com:9099
      - api2.2gis.com:9199
    labels:
      job: bizaccount
      type: nginx
      role: monitoring-api-methods
      team: lk
      project: backend

В разделе targets указываются endpoint наших нод, в разделе labels — лейблы, которые добавляются к собираемым метрикам. По ним определяем назначение метрики и отправителя.

Сбор метрик у нас настроен каждые 15 секунд — Prometheus заходит на указанные ноды и сохраняет себе метрики.

После того, как мы разобрались с метриками, научились их собирать, отдавать в Prometheus, мы перешли к тому, ради чего затевалась интеграция — оповещения на командную почту при падении скорости работы нашего приложения. Вот пример оповещения:

ALERT BizaccountAPI95PercentileUnreachebleGetUsers
        IF (sum(rate(nginx_http_request_time_bucket{le="0.4",api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method)
/
sum(rate(nginx_http_request_time_count{api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method)) * 100 < 95
        FOR 5m
        LABELS { severity = "critical", team = "lk"}
        ANNOTATIONS {
                summary = "API-method {{ $labels.request_method}} {{ $labels.api_method_end_point}} is not in SLA",
                description = "For API-method {{ $labels.request_method}} {{ $labels.api_method_end_point }} 95 percentile is unreacheble in last 5 minutes. Current percentile is {{ $value }}.",
        }

У Prometheus лаконичный язык формирования запросов, при помощи которого можно выбирать значения метрик за период и фильтровать по лейблам. В директиве IF с помощью конструкций языка указываем условие срабатывания триггера — если за 0.4 секунды отвечают менее 95 процентов запросов за последние 5 минут. Считается это отношением. В числителе мы высчитываем, сколько запросов укладываются за 0.4 секунды за последние 5 минут:

sum(rate(nginx_http_request_time_bucket{le="0.4",api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method)

В знаменателе считаем общее количество запросов за последние 5 минут:

sum(rate(nginx_http_request_time_count{api_method_end_point="/users",request_method="GET"}[5m])) by (api_method_end_point, request_method)

Полученную дробь умножаем на 100 и получаем процент запросов, которые отвечают за 0.4 секунды. Функция rate здесь возвращает время ответа за каждый момент в указанный интервале. Функция sum суммирует полученный ряд. Оператор by — это аналог оператора GROUP BY, который выполняет группировку по указанным лейблам.

В разделе FOR указывается интервал между первым срабатываем триггера и моментом, когда нужно отправить оповещения. У нас интервал равен 5 минутам — если за 5 минут ситуация не меняется, то нужно отправить оповещение. В разделе LABELS указываются лейблы с указанием команды и критичности проблемы. В разделе ANNOTATIONS указывается проблемный метод и какой процент запросов отвечает за 0.4 секунды.

В случае возникновения повторяющихся оповещений Prometheus умеет делать дедупликацию, и отправит одно оповещение на командную почту. И это всё из коробки, нам нужно лишь указать правила и интервал срабатывания триггера.

Оповещения в Prometheus получились именно такими, какими мы и хотели — с понятной конфигурацией, без своих велосипедов с дедупликацией оповещений и без реализации логики срабатывания оповещения на каком-либо языке.

Вот как выглядит сообщение:

Заключение

Мы улучшили нашу систему логирования и теперь у нас не возникает проблем с недостатком информации.

1. При возникновении ошибки мы обладаем достаточной информацией о проблеме. Теперь на 99 процентов запросов техподдержки мы имеет представление, что произошло у пользователя и точно сориентировать техподдержку о проблеме и возможных сроках исправления.
2. С помощью оповещений мы определяем проблемные места в производительности приложения и оптимизируем их, делая приложение быстрее и надёжнее.
3. Через Prometheus мы оперативно узнаём о падении скорости, а уже после смотрим в ELK и начинаем детально изучать, что случилось. У связки ELK + Prometheus мы видим большой потенциал, планируем добавить оповещения в случае увеличения ошибок и мониторинг внешних сервисов.

Точно так же как безопасность, регистрация системных сообщений – другой ключевой компонент веб-приложений (или приложений в целом), который отодвигается на второй план из-за старых привычек и неспособности видеть впереди.

То, что многие считают бесполезными набросками цифровой ленты, – это мощные инструменты, позволяющие заглянуть в ваши приложения, исправить ошибки, улучшить слабые места и порадовать клиентов.

Прежде чем мы перейдем к централизованному ведению журналов, давайте сначала рассмотрим, почему ведение журналов ( логирование ) так важно.

Два типа (уровня) регистрации сообщений журналов

Компьютеры являются детерминированными системами, кроме случаев, когда это не так.

Как безопасник, я сталкивался со многими случаями, когда наблюдаемое поведение приложения ставило всех в тупик целыми днями, но ключ к разгадке всегда был в журналах.

Каждое программное обеспечение, которое мы запускаем, производит (или, по крайней мере, должно генерировать) журналы, которые сообщают нам, через что они проходили, когда возникала проблемная ситуация.

Теперь, как мне кажется, ведение журнала бывает двух типов: автоматически сгенерированные журналы и сгенерированные программистом журналы.

Обращаем ваше внимание, что этих различий и классификации нету в учебниках, и цитирование меня по этой терминологии доставит вам неприятности. ?

Изображение выше показывает то, что можно назвать автоматически сгенерированным журналом.

В данном конкретном случае это система WordPress, регистрирующая непредвиденное состояние (уведомление) при запуске некоторого кода PHP.

Журналы, подобные этим, создаются постоянно – с помощью инструментов баз данных, таких как MySQL, веб-серверов, таких как Apache, языков программирования и сред, мобильных устройств и даже операционных систем.

Они редко содержат большую ценность, и программисты даже не удосуживаются их изучить, кроме случаев, когда что-то идет не так.

В такие моменты они копаются глубоко в коде, пытаясь понять, что пошло не так.

Но автоматически сгенерированные журналы могут помочь только так сильно.

Если несколько человек имеют доступ администратора к сайту, например, и один из них удаляет важную часть информации, невозможно обнаружить виновника с помощью автоматически сгенерированных журналов.

С точки зрения систем, связанных как приложение, это был просто еще один день в работе – кто-то имел необходимые полномочия для выполнения задачи, и поэтому система выполнила ее.

Здесь нужен дополнительный уровень явной, обширной регистрации, которая создает следы для человеческой стороны вещей.

Это то, что я называю созданными программистом журналами, и они составляют основу чувствительных отраслей, таких как банковское дело.

Вот пример того, как может выглядеть такая схема регистрации:

Логгирование это сила

Итак, с учетом этих двух типов журналов в системе, вот как вы можете использовать их и усилить воздействие.

Боевой дух и продуктивность команды

Как я уже говорил, когда ошибки долго не отслеживаются, разработчики в вашей команде разочаровываются и теряют все больше и больше времени, закрывая свои хвосты.

И вот в чем дело с отладкой – она требует свежего, любопытного ума с самого начала.

И что затрудняет отладку?

По моему опыту, отсутствие ведения журнала или отсутствие знаний о ведении журнала.

Для начала вы можете не осознавать, что ваша любимая база данных – это просто еще одна часть программного обеспечения, которая генерирует журналы, или вы не будете интенсивно регистрировать события в своем приложении (см. Журналы, сгенерированные программистом выше).

Я особенно помню случай, когда приложение перестало отвечать на запросы, и никто не знал, почему.

Несколько дней спустя виновником стало ограничение дискового ввода-вывода из-за чрезмерного трафика.

Потому что никто не удосужился посмотреть журналы,и никто не мог понять, почему система упала.

Если вы регулярно посещаете журнал медленных запросов, вы узнаете, какие операции занимают больше всего времени, и, следовательно, обнаружите небольшие, но важные области, требующие работы.

Часто такие небольшие изменения работают лучше, чем удвоение емкости оборудования.

Невозможно сосчитать, сколько способов решения проблем подарит вам хорошая система журналов.

Возможно, лучшим аргументом является то, что это автоматическое действие, которое когда-то настроено, не нуждается в каком-либо мониторинге и однажды спасет вас от разорения.

В связи с этим давайте рассмотрим некоторые из удивительных сборщиков журналов с открытым исходным кодом (унифицированных инструментов ведения журналов).

1 Graylog

Как мониторить лог файлы с помощью GrayLog Linux

2 Logstash

Если вы являетесь поклонником или пользователем стека Elastic, стоит попробовать Logstash (стек ELK )

Как и другие инструменты ведения журнала в этом списке, у Logstash,полностью открытый исходный код, дает вам свободу развертывания и использования по своему усмотрению.

Но не вводите себя в заблуждение: Logstash – это иснтрумент, возможности которого намного превосходят любые скромные средства ведения журналов.

Он способен собирать огромные объемы данных с разных платформ, позволяет определять и выполнять собственные конвейеры данных, понимать неструктурированные дампы журналов и многое другое.

Конечно, единственным ограничением является то, что он работает только с набором продуктов Elastic, но если вы скоро начнете и хотите масштабироваться, Logstash – это то, что вам нужно!

3 Fluentd

Среди централизованных инструментов ведения журналов, которые выполняют роль промежуточного уровня для приема данных, Flutend является первым среди равных.

Обладая превосходной библиотекой плагинов, Fluentd может собирать данные практически из любой производственной системы, перемешивать их в нужной структуре, создавать собственный конвейер и передавать его на свою любимую аналитическую платформу, будь то MongoDB или Elasticsearch.

Fluentd построен на Ruby, является продуктом с полностью открытым исходным кодом и пользуется большой популярностью благодаря своей гибкости и модульности.

С такими крупными компаниями, как Microsoft, Atlassian и Twilio, использующим эту платформу, Fluentd нечего доказывать. ?

4 Flume

Если на самом деле вам нужны действительно большие наборы данных, и вы в конечном итоге захотите объединить все в нечто вроде Hadoop, Flume – один из лучших вариантов.

Это «чистый» проект с открытым исходным кодом, в том смысле, что он поддерживается нашим любимым Apache Foundation, что означает отсутствие корпоративного плана.

Это может  быть то, что вы точно ищете. ?

Написанный на Java (который продолжает удивлять меня, когда дело доходит до революционных технологий), исходный код Flume полностью открыт.

Flume лучше всего подойдет вам, если вы ищете распределенную отказоустойчивую платформу для загрузки данных для работы в тяжелых условиях.

5 Octopussy

Я даю ноль из десяти наименованию продукта, но Octopussy может быть хорошим выбором, если ваши потребности просты, и вы задаетесь вопросом о том, что же такое суета, связанная с конвейерами, приемом, агрегацией и т. д

По моему мнению, Octopussy покрывает потребности большинства продуктов (оценочная статистика бесполезна, но, если бы мне пришлось угадывать, я бы сказал, что в реальном мире она учитывает 80% случаев использования)

У Octopussy нет отличного пользовательского интерфейса:

но он компенсирует скорость и отсутствие раздувания.

Исходный код доступен на GitHub, как и ожидалось, и я думаю, что он заслуживает серьезного изучения.

6 LOGalyze

LOGalyze был коммерческим продуктом, который недавно стал инструментом с открытым исходным кодом.

Хотя я не смог реализовать проект на GitHub, они сделали установщик Windows и весь исходный код загружаемым.

Если вы намерены участвовать в сообществе, вы можете найти подробную информацию о списке рассылки здесь.

LOGalyze – это относительно гибкое и мощное предложение, которое отлично подойдет для развертываний в одной системе, которые стремятся объединить ведение журналов из известных источников, таких как Postfix, Apache и т. д. и выводить их в форматах CSV, PDF, HTML или аналогичных.

Да, он не делает все, но поскольку это был коммерческий продукт в свое время, он делает это довольно хорошо.

7 LogPacker

Когда дело доходит до выбора инструмента для работы, у меня есть два критерия: он должен быть целенаправленным и опираться на активную бизнес-модель.

Проблема программного обеспечения с открытым исходным кодом, как правило, заключается в том, что через несколько месяцев / лет вероятность застоя или выхода из строя высока.

Там нет подсчета того, сколько инструментов ведения журнала было запущено,а только можно найти количество на кладбище GitHub.

По этому критерию LogPacker – мой любимый.

8 Logwatch

Я уверен, что среди нас есть те, кто не хочет, чтобы вся церемония была связана с «единой», «централизованной» системой ведения журналов.

Их бизнес базируется на отдельных серверах, и они ищут что-то быстрое и эффективное для просмотра своих файлов журналов.

Ну тогда, скажи привет Logwatch.

После установки LogWatch может сканировать системные журналы и создавать отчеты нужного вам типа.

Это несколько устаревшее программное обеспечение (читай «надежное»), хотя оно было написано на Perl.

Итак, вам понадобится Perl 5.6+ на вашем сервере для его запуска.

У меня нет скриншотов, которыми можно поделиться, потому что это чисто командная строка, демонизированный процесс.

Если вы наркоман CLI и любите стиль старой школы, вам понравится Logwatch!

9 Syslog-ng

Инструмент Syslog-ng был разработан как способ обработки файлов  системного журнала (установленный протокол клиент-сервер для регистрации в системе) в режиме реального времени.

Однако со временем он стал поддерживать другие форматы данных: неструктурированные, SQL и NoSQL.

Как работает протокол системного журнала, довольно четко подытожено на следующем рисунке.

syslog-ng – это надежный инструмент для сбора и классификации журналов промышленного уровня, написанный на языке Си и давно известный в отрасли.

Лучшая часть – это расширяемость, позволяющая вам писать плагины на C, Python, Java, Lua или Perl.

10 Inav

✗ Установите и используйте Log File Navigator – lnav в Ubuntu и CentOS ✗

От глупой командной строки, не требующих настройки инструментов до полномасштабной обработки данных – все это здесь!

Я что-то пропустил? Конечно, я сделал это!

Пожалуйста, дайте мне знать в комментариях, и я буду рад добавить эту сюда

Теги: devops, системы логирования, логи, graylog, elk, loggy, splunk, mongodb, микросервисы

К логам сервисов и приложений обращаются абсолютно все: администраторы читают логи, чтобы выяснить причину сбоя сервиса; программисты ищут в них исключения; «безопасники» проверяют, что в них нет каких-нибудь необычных записей, характерных для взлома.

Пока у вас один сервер, всё хорошо: каждый специалист может открыть файлы в vim и посмотреть, что ему нужно. А что если серверов у вас много? А что если по этим серверам разбросаны кучи сервисов и приложений? Как людям читать логи со всего этого?

Придётся же читать логи каждого сервиса, каким-то сложным методом находить логи того запроса, что сломался, и искать где именно что-то пошло не так. Как решить эти проблемы?

Существуют популярные системы логирования: Graylog, ELK, Loggy или Splunk

Эти системы занимаются тем, что собирают все логи всех сервисов в централизованное хранилище и предоставляют к нему интерфейс, дающий возможность искать по логам, фильтровать их, строить графики и дашборды.

Что эта система даёт администраторам?

Им больше не нужно подключаться ко всем серверам, достаточно открыть веб-интерфейс системы логирования и в поиске написать название сломанного сервиса. Например, вы вводите слово Mongo и получаете журнал MongoDB со всех своих серверов, с возможностью фильтровать их по полям.

Мы предполагаем, что где-то возникла ошибка, поэтому добавляем фильтр по полю. Указываем, что «критичность логов» должна быть «ERROR», после чего система нам покажет все ошибки с заданной критичностью. Если администратор не исправляет ошибку, а пишет «постмортем» по вчерашней аварии, он также может добавить фильтр по времени и посмотреть логи за весь вчерашний день, за конкретные его часы и т.д.

Что эта система даёт программистам?

В некоторых компаниях программистам не дают доступ к серверам, с этой системой они могут смотреть все интересующие их логи, не заходя в них! Частой проблемой является поиск сервера, на котором произошло исключение. Мы можем просто написать исключение в строке поиска, найти, на каком сервере это произошло, и посмотреть весь его журнал в считанные секунды. Поверх логов с исключениями можно построить график количества исключений в час/день/и т.д., чтобы отследить возрастание ошибок после деплоя и вовремя откатиться на предыдущий релиз.

Что эта система даёт Q/A?

Во-первых, они по логам могут проанализировать, состояние сервисов после прогона тестов – не появилось ли там новых ошибок. Если же ошибки появились, можно передать программисту ссылку на все эти сообщения.

Во-вторых, они могут построить график количества ошибок/предупреждений в логах и на их основе принимать решения, пропускать релиз дальше или нет.

Микросервисы

Это особенный случай. Тут серверов много, на одном сервере может быть несколько одинаковых микросервисов. Какой запрос где сломался, вообще не поймёшь. В таких сложных ситуациях прибегают к практике сквозного логирования, при которой каждому запросу присваивается ID, передающийся от сервиса к сервису на протяжении всей жизни запроса. Этот ID так же добавляют в логи, и когда мы получаем исключение, мы видим не только ошибку, но и в каком конкретно запросе оно произошло.

Вбиваем этот ID в систему логирования и видим полное развитие событий: от начала до конца. Ага, вот запрос прошёл балансировку, вот произошла авторизация пользователя, вот он начал собирать данные, обходя множество микросервисов, и вот тут конкретный микросервис вернул ошибку. Дальше можно проследить и обратную цепочку того, как ошибка прошла весь этот путь обратно и показалась пользователю, но, как правило, это уже не так важно.

Есть вопрос? Напишите в комментариях!

Этот материал мы ориентировали на тех, кто в первый раз сталкивается с логированием серверных служб и web-серверов. Познакомим с уровнями логирования, расскажем об основных типах логов и перечислим инструменты для работы с ними.

Зачем оно вообще нужно, это логирование?

На анализе логов базируется работа большинства ИТ-специалистов. Администраторы  ищут в файлах логирования причины сбоя сервиса. Разработчики опираются на логи, чтобы локализовать и устранить ошибки приложения или веб-сайта. Служба безопасности по логам, как по физическим уликам, определяет вид взлома, оценивает нанесенный ущерб и даже может идентифицировать взломщика. Вот почему логирование мы рекомендуем отладить в первую очередь: в любой непонятной ситуации ответ на вопрос вы будете искать в логах!

Файлы логирования

Уровни логирования

В идеале логи пишутся во время работы всех IT-систем, однако если писать все подряд и «складывать в кучу», полезная информация превратится в хаос. Чтобы упростить поиск и чтение логов, их делят на уровни. Основных четыре:

1. Debug — запись масштабных переходов состояний, например, обращение к базе данных, старт/пауза сервиса, успешная обработка записи и пр.

2. Warning — нештатная ситуация, потенциальная проблема, может быть странный формат запроса или некорректный параметр вызова.

3. Error — типичная ошибка.

4. Fatal — тотальный сбой работоспособности, когда нет доступа к базе данных или сети, сервису не хватает места на жестком диске.

Дополнительно файл логирования может расширяться записями еще двух уровней:

1. Trace  — пошаговые записи процесса. Полезен, когда сложно локализовать ошибку.

2. Info — общая информация о работе службы или сервиса.

Работа с уровнями логирования регламентируется методическими документами и внутренними правилами организации. В них может определяться соответствие источника сообщения уровню логирования, значимость, порядок обработки каждого уровня и другие параметры.

Типы логов

Для удобства обработки логов их делят на типы:

• системные, связанные с системными событиями,

• серверные, отвечающие за процесс обращения к серверу,

• почтовые, работающие с отправлениями,

• логи баз данных, которые отражают процессы обращения к базам данных,

• авторизационные и аутентификационные, которые отвечают за процесс входа, выхода из системы, восстановление доступа и пр.

У каждого типа логов свой журнал записи. Для проверки логов авторизации нужно идти в журнал доступов, чтобы проверить загрузку системы — в журнал dmesg, за данными о запросах пользователей — в access_log. Когда одни логи пишутся отдельно от других, проще диагностировать ситуацию и найти источник проблемы.

Логи в access_log

Инструменты для работы с логами

Сбор, хранение и анализ логов вручную хороши, когда у вас один сервер. Когда серверный парк разрастается, а приложений и сервисов становится больше десяти, работу с логами целесообразно автоматизировать и использовать специальные системы логирования, например, Graylog, ELK, Loggy или Splunk. Некоторые из них позволяют организовать полномасштабный мониторинг, настроить алерт раннего обнаружения конкретной проблемы или установить пороговые значения показателей, коррелирующих с угрозами информационной безопасности. 

Логи сетевого, инженерного оборудования, баз данных и приложений мы храним в облачном хранилище. И вам советуем. Даже когда у вас полно места на жестких дисках и стоит мощная защита на все случаи жизни. Оборудование рано или поздно, а чаще неожиданно, выходит из строя, а злоумышленники давно умеют чистить файлы логирования, так что логи в облаке — это возможность восстановить события и расследовать инцидент даже при полном отказе системы.

Хранение логов в облаке

Логирование кажется второстепенным процессом, который занимает время, но не дает видимых результатов. Однако это только кажется и только до тех пор, пока не появится реальная проблема, с которой можно разобраться только по логам. И только если они записаны, распределены по уровням, собираются и доступны для анализа.

Привет! Это вторая часть статьи, в которой мы будем разбирать практическое применение платформы Graylog.

В первой части мы разобрали как платформу установить и произвести ее базовую настройку, а сегодня рассмотрим пару примеров применения ее возможностей на практике.

В частности, разберем настройку сбора логов с веб-сервера и возможность визуализировать полученные данные.

Настраиваем сбор логов с сервера

Работаем в web-интерфейсе:

https://graylog.itsft.ru

Начнем со сбора syslog

Создаём UDP Input для системных логов:

System/Overview → Inputs

Выбираем тип Input-а:

Select input → Syslog UDP

(Будем использовать UDP, но если кому-то удобнее использовать tcp — почему бы и да)

Нажимаем кнопку Launch new input.

Title:        SyslogUDP 
Bind address: 0.0.0.0
Port:         10514

Внимание!

Порты меньше чем 1024 использовать можно только через костыли, поэтому будем использовать 10514: 
http://docs.graylog.org/en/2.4/pages/faq.html#how-can-i-start-an-input-on-a-port-below-1024

Остальные значения можно оставить по умолчанию:

Сохраняем конфигурацию, получаем работающий Input:

Для проверки работы Input выполним со своей рабочей станции или с любого другого хоста с linux/mac:

$ echo "Hello world" | nc -w 1 -u graylog.itsft.ru 10514

Переходим в веб-интерфейсе Show received messages, видим полученное сообщение.

Настройки для сервера с которого собираем логи:

Уменьшаем количество логов

May  1 11:01:01 localhost systemd: Created slice User Slice of root.
May  1 11:01:01 localhost systemd: Started Session 541 of user root.
May  1 11:01:01 localhost systemd: Removed slice User Slice of root.

# vim /etc/rsyslog.d/ignore-systemd-session-slice.conf

if $programname == "systemd" and ($msg contains "Starting Session" or $msg contains "Started Session" or $msg contains "Created slice" or $msg contains "Starting user-" or $msg contains "Starting User Slice of" or $msg contains "Removed session" or $msg contains "Removed slice User Slice of" or $msg contains "Stopping User Slice of") then
    stop

Передаём логи в Graylog:

# vim /etc/rsyslog.d/90-graylog2.conf

Если передаём данные по UDP, как сейчас настроено в инпуте Graylog-а:

*.* @11.22.33.44:10514;RSYSLOG_SyslogProtocol23Format

Но если нужно по TCP, добавляем ещё одну “@”:

*.* @@11.22.33.44:10514;RSYSLOG_SyslogProtocol23Format

После редактирования делаем рестарт сервиса:

# systemctl restart rsyslog.service

Проверяем наличие данных от хоста в Graylog-е. 

На этом настройку сбора syslog считаем завершённой. На случай чрезвычайных ситуаций, или просто для информации, полезны будут оповещения о событиях (ошибках дисков, нехватке памяти, логинах, etc).

Настраиваем оповещения

Для примера — отловим приход oom-killer-а c уведомлением в Slack:

Alerts  →  Alerts & Events  →  Get Started!

Шаг 1: “Event Details”:

Title: oom-killer invoked

Description (Optional):  oom-killer was invoked on server or virtual machine

Priority: Normal

Шаг 2: “Filter & Aggregation”:

Condition Type:  Filter & Aggregation

Search Query: "oom-killer"

(Тут правила построения запроса)

Streams (Optional):  All messages

Search within the last:  10 minutes

Execute search every:  10 minutes

Устанавливаем чекбокс Enable

Create Events for Definition if…   Filter has results

Если в логах уже есть такое событие, можно будет наблюдать его в Filter preview.

Шаг 3: «Fields» — не используем.

Шаг 4: «Notifications»  →  Add Notification:

Choose Notification:  Create New Notification...

Title: Slack notification

Notification Type: Slack Notification

Configuration Color:  можно выбрать цвет

Webhook URL:  Выглядит как https://hooks.slack.com/services/aaa/bbb123 — можно создать его в настройках Slack.

Channel:  #monit  (в какой канал будут приходить данные уведомления).

Custom Message (optional): можно выбрать какие поля оставляем в сообщении.

Остальные настройки можно оставить по умолчанию.

Нажимаем кнопку Execute test notification,  контролируем доставку сообщения в указанный канал Slack-а, и если всё работает — нажимаем кнопку Done.

В Notification Settings ничего изменять не будем:

Шаг 5: «Summary»:  Ещё раз удостоверимся что настройки верны. 

Нажимаем Done.

Тестируем оповещение. На хосте, с которого собираем syslog пишем маленькую программку на С:

# vi memtest1.c

#include <stdio.h>
#include <stdlib.h>
int main (void) {  
  int n = 0;  
  while (1) {  
    if (malloc(1<<20) == NULL) {  
      printf("malloc failure after %d MiBn", n);  
      return 0;  
    }  
    printf ("got %d MiBn", ++n);  
  }  
}

Компилируем и запускаем. Скрипт занимает всю доступную память, после чего приходит oom-killer и его убивает:

# gcc memtest1.c  
# ./a.out
got 1 MiB
...
got 94372 MiB
Killed

В /var/log/messages можем наблюдать данный процесс:

May  4 17:24:50 docker kernel: Out of memory: Kill process 23219 (a.out) score 831 or sacrifice child
May  4 17:24:50 docker kernel: Killed process 23219 (a.out), UID 0, total-vm:659692616kB, anon-rss:2181712kB, file-rss:0kB, shmem-rss:0kB
May  4 17:27:19 docker kernel: dockerd-current invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=-500
May  4 17:27:19 docker kernel: dockerd-current cpuset=/ mems_allowed=0
May  4 17:27:19 docker kernel: CPU: 1 PID: 18617 Comm: dockerd-current Kdump: loaded Tainted: G               ------------ T 3.10.0-1160.21.1.el7.x86_64 #1
May  4 17:27:19 docker kernel: Hardware name: Red Hat KVM, BIOS 1.11.0-2.el7 04/01/2014

В Slack видим оповещение о событии (здесь сообщение стандартное, по умолчанию, но его можно кастомизировать под ваши требования):

Graylog Sidecar

Graylog может собирать также логи сервисов, и вообще практически любые логи.

Будем использовать Graylog Sidecar для управления конфигурацией и бэкенд Filebeat, который собирает события и отправляет на Graylog-сервер. Схема работы для данного кейса:

Картинка отсюда.

Мы будем работать с access-логами веб-сервера nginx, работающего под CentOS linux.

PS:

Получаем токен

System  →  Sidecars:

Нажимаем на ссылку:

Do you need an API token for a sidecar?   Create or reuse a token for the graylog-sidecar user

Ранее созданные токены также можно найти по этой ссылке.

Вводим имя токена:

Token Name:  myToken

Нажимаем кнопку Create Token

Там же можно скопировать его в буфер обмена, если нужно кнопкой Copy to clipboard, предварительно убрав чекбокс Hide Tokens.

System  →  Inputs:

Выбираем тип инпута Beats, жмём Launch New Input

Настройка в данном случае практически не отличается от той, что делали для syslog

Устанавливаем чекбокс Global:

Title:   graylog-sidecar

Bind address:   0.0.0.0

Port:    5044

Остальное оставляем по умолчанию (разумеется, в продакшн-среде, особенно при передаче сенситивных данных нужно будет добавить SSL-сертификаты, но пока обойдемся без них).

Нажимаем кнопку Save.

Не забываем добавить правило для 5044/tcp в Firewall.

Также нужен будет 443-й порт, но он у нас уже должен быть открыт:

# firewall-cmd --permanent --zone=itsoft --add-port=5044/tcp
# firewall-cmd --reload

System  →  Sidecars  →  Configuration 

В секции Configuration нажимаем кнопку Create Configuration:

Name:  filebeat_conf

Configuration color:    можно выбрать желаемый цвет

collector:   filebeat on linux

Configuration редактируем следующим образом

(paths — путь, где лежат лог-файлы сервиса,
hosts — ip-адрес и порт graylog-сервера):

# Needed for Graylog
fields_under_root: true
fields.collector_node_id: ${sidecar.nodeName}
fields.gl2_source_collector: ${sidecar.nodeId}

filebeat.inputs:
- input_type: log
  paths:
    - /var/log/nginx/access.log
  type: log
output.logstash:
   hosts: ["213.79.122.211:5044"]
path:
  data: /var/lib/graylog-sidecar/collectors/filebeat/data
  logs: /var/lib/graylog-sidecar/collectors/filebeat/log

Нажимаем кнопку Create:

Далее необходимо установить менеджер конфигурации и коллектор на хосте, с которого будет производиться сбор логов:

Sidecar

# rpm -Uvh https://packages.graylog2.org/repo/packages/graylog-sidecar-repository-1-2.noarch.rpm
# yum -y install graylog-sidecar

# vim /etc/graylog/sidecar/sidecar.yml

Обязательно, вносим в файл конфигурации строки:

server_url: "https://graylog.itsft.ru/api/"

server_api_token: "1m6dk8vu3dk6uim9nbvmk1nkup4mvak2mrjfbtom3kgdafg2ms49"

# graylog-sidecar -service install
# systemctl enable graylog-sidecar.service
# systemctl start graylog-sidecar.service
# systemctl status graylog-sidecar.service
● graylog-sidecar.service - Wrapper service for Graylog controlled collector
   Loaded: loaded (/etc/systemd/system/graylog-sidecar.service; enabled; vendor preset: disabled)
   Active: active (running) since Wed 2021-05-05 11:11:20 MSK; 6s ago

Полезная информация:

https://graylog.itsft.ru/api/api-browser — REST API Browser

filebeat

# rpm --import https://packages.elastic.co/GPG-KEY-elasticsearch

# vim /etc/yum.repos.d/elastic.repo

[elastic-7.x]
name=Elastic repository for 7.x packages
baseurl=https://artifacts.elastic.co/packages/7.x/yum
gpgcheck=1
gpgkey=https://artifacts.elastic.co/GPG-KEY-elasticsearch
enabled=1
autorefresh=1
type=rpm-md

# yum -y install filebeat
# systemctl enable filebeat.service
# systemctl start filebeat.service
# systemctl status filebeat.service
● filebeat.service - Filebeat sends log files to Logstash or directly to Elasticsearch.
   Loaded: loaded (/usr/lib/systemd/system/filebeat.service; enabled; vendor preset: disabled)
   Active: active (running) since Wed 2021-05-05 12:16:37 MSK; 6s ago

Не забываем про правило firewall с соответствующим портом, если это необходимо:

# firewall-cmd --zone=itsoft --add-ports=5044/udp
# firewall-cmd --runtime-to-permanent

Теперь Sidecar должен быть виден в System  →  Sidecars  →  Overview

Назначим созданную конфигурацию на этот Sidecar.

Нажимаем кнопку Administration:

filebeat  →  Configure  →  выбираем нужную конфигурацию:

В открывшемся поп-апе подтверждаем, что всё верно  →  Confirm:

Контролируем статус — Running.

Идём в System  →  Inputs, на инпуте graylog-sidecar нажимаем Show received messages,

наблюдаем логи nginx:

Extractor

Полезные ссылки:

Просто хранение лога — не та задача к которой мы шли. Нам нужно парсить и анализировать эти логи!

Настраиваем экстрактор:

System  →  Inputs  →  Manage extractors

В секции Add extractor нажимаем единственную кнопку — Get started

Выбираем нужный Sidecar, затем нажимаем кнопку Load Message

Recent message выбирает последнее пришедшее сообщение, но удобнее выбрать нужное сообщение по message_id и index. 

Парсить будем само сообщение:

На поле message нажимаем Select extractor type  →  Grok pattern

Лог nginx по умолчанию имеет формат (можем найти его в nginx.conf):

log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                  '$status $body_bytes_sent "$http_referer" '
                  '"$http_user_agent" "$http_x_forwarded_for"';

Grok pattern будет выглядеть так:

%{IP:remote_addr} - - [%{HTTPDATE:time_local;date;dd/MMM/yyyy:HH:mm:ss Z}] "%{NOTSPACE:request_method} %{DATA:request_uri} HTTP/%{NUMBER:http_version}" %{NUMBER:http_status_code} %{NUMBER:body_bytes_sent} %{QS:http_referrer} %{QS:http_user_agent} %{QS:http_x_forwarded_for}

Нажимаем Try against example и в Extractor preview проверяем правильность паттерна:

Остальные параметры можно оставить по умолчанию, только имя нужно будет указать:

Condition:   Always try to extract

Extraction strategy:   Copy

Extractor title:   nginx combined

Нажимаем Create extractor

Переходим в меню System  →  Inputs  →  Show received messages, в инпуте graylog-sidecar.

Теперь все новые логи будут содержать отдельные поля message:

Поиск по логам стал намного проще, например:

gl2_source_input:6091644a7f58801671462478 — все сообщения с данного инпута;

gl2_source_input:6091644a7f58801671462478 AND request_method:POST — все сообщения с методом POST;

gl2_source_input:6091644a7f58801671462478 AND NOT http_status_code:200 — не 200-й ответ.

При составлении запроса Graylog подсказывает параметры, что довольно удобно:

Также будет полезно создать Stream (поток).

Он нам нужен будет в дальнейшем:

Streams  →  Create stream

Title:  Sidecars

Description:  Nginx access logs

Index Set:  Default index set

Сохраняем кнопкой Save

Stream создан, но пока неактивен.

Добавляем правило для этого потока (кнопка Manage Rules):

Выбираем нужный Input, создаём правило (кнопка Add stream rule).

В поп-апе New Stream Rule:

Требуется все сообщения из Sidecar-а поместить в этот поток, поэтому:

Type: match input

Value: graylog-sidecar

Сохраняем кнопкой Save.

Правило добавлено, сохраняем кнопкой I’m done!:

Запускаем поток: Start stream. 

Нажав на имя потока Sidecars можем также просматривать сообщения в нём и производить поиск по этим сообщениям.

Немного бесполезного, но красивого

На этапе установки, в первой части статьи мы прикрутили к graylog-у базу geoip. 

Теперь посмотрим, как её использовать, а также выведем карту мира, визуально демонстрирующую, откуда к нам на сайт приходят посетители.

Создаём data adapter

System  →  Lookup Tables  →  кнопка Data Adapters  →  Create data adapter:

Data adapter type  →  Geo IP — MaxMindTM Databases

Title:  GeoIP

Description:   GeoIP Lookup Table

Name:  geoip

File Path:   /etc/graylog/server/GeoLite2-City.mmdb

Database type:  City database

Остальное по умолчанию.

Для завершения нажимаем кнопку Create adapter.

Когда результаты кешируются — всё становится лучше

Создаём Caches:

System  →  Lookup Tables  →  кнопка Caches  →  кнопка Create cache

Cache Type:  Node-local, in-memory cache

Title:  GeoIP

Description:  GeoIP Cache

Name:  geoip

Остальное можно оставить по умолчанию.

Нажимаем кнопку Create Cache:

Создаём Lookup table:

System  →  Lookup Tables  →  Lookup Tables (активна по умолчанию)  →  Create Lookup Table

Title: GeoIP

Description:  GeoIP Lookup

Name: geoip

Data Adapter:  GeoIP (geoip)

Cache:  GeoIP (geoip)

Нажимаем кнопку Create Lookup Table:

Создаём Pipeline (пайплайны позволяют обрабатывать сообщения из потоков):

Сначала правило:

System  →  Pipelines  →  кнопка Manage rules  →  кнопка Create Rule

Description: Incoming connections

Rule source:

rule "GeoIP lookup: remote_addr"
when
  has_field("remote_addr")
then
  let geo = lookup("geoip", to_string($message.remote_addr));
  set_field("remote_addr_geo_location", geo["coordinates"]);
  set_field("remote_addr_geo_country", geo["country"].iso_code);
  set_field("remote_addr_geo_city", geo["city"].names.en);
end

Нажимаем кнопку Save&Close.

Теперь пайплайн:

System  →  Pipelines  →  кнопка Manage pipelines  →  кнопка Add new pipeline

Title:  Web

Description:  Incoming connections

Наблюдаем сообщение, что только что созданный пайплайн не подключен ни к одному потоку: 

Нажимаем кнопку Edit connections, подключаем:

А также в Stage 0 нажимаем Edit и добавляем к нему правило:

Идём в Streams  →  Sidecars, смотрим новые сообщения…

Проблема — ничего не происходит 🙁  Никаких гео-тегов не видно :((

Проблема возникает из-за порядка обработки правил.

Идём в System  →  Configurations

По умолчанию так:

1    AWS Instance Name Lookup

2    GeoIP Resolver

3    Pipeline Processor

4    Message Filter Chain

А нам нужно так:

1    AWS Instance Name Lookup

2    GeoIP Resolver

3    Message Filter Chain

4    Pipeline Processor

Нажимаем кнопку Update, перетаскиванием располагаем правила в правильном порядке:

Снова идём в Streams  →  Sidecars, смотрим новые сообщения и видим в них искомые геоданные:

Теперь будем смотреть красивую карту:

В Streams  →  Sidecars  добавляем Aggregation:

Нажимаем Edit:

Visualization type: World Map

Rows: remote_addr_geo_location

Сохраняем:  Save

Теперь можно визуально оценить откуда к нам на сайт приходят посетители:

На этом всё, надеемся, что данная информация будет вам полезна.

Данная статья изначально появилась в виде заметки / howto для внутреннего использования, поэтому может местами быть немного запутанной. Ждем ваши вопросы, предложения и замечания в комментариях!

Описание сервиса логирования.

Устройство системы логирования Flexberry Ember

Сервис логирования представляет собой один из доступных во фреймворке Flexberry Ember сервисов и обеспечивает запись сообщений различного уровня в базу данных приложения.

Сервис логирования Flexberry Ember расширяет возможности стандартного логгера фреймворка Ember.js.

При инициализации приложения данный сервис автоматически внедряется с именем logService на уровни:

• Роут,
• Компонент,
• Контроллер.

По умолчанию сервис логирования выключен, существует возможность включить его как программно, так и в файле конфигурации.

Возможности сервиса log

Уровни логирования

Сервис логирования поддерживает семь уровней логирования:

• ERROR — уровень ошибок;
• WARN — уровень предупреждений;
• LOG— уровень логов;
• INFO— уровень информационных сообщений;
• DEBUG— уровень отладочных сообщений;
• DEPRECATION— уровень сообщений о подозрительных и устаревших участках исходного кода;
• PROMISE— уровень ошибок промисов.

Разработчик может самостоятельно сгенерировать сообщения данных уровней, используя соответствующие методы класса Ember.Logger:

Ember.Logger.error('Текст сообщения об ошибке'); // уровень ошибок
Ember.Logger.warn('Текст предупреждения'); // уровень предупреждений;
Ember.Logger.log('Текст лога'); // уровень логов;
Ember.Logger.info('Информационный текст'); // уровень информационных сообщений;
Ember.Logger.debug('Отладочный текст'); // уровень отладочных сообщений;
Ember.Logger.warn('DEPRECATION "Текст лога"'); // уровень сообщений о подозрительных и устаревших участках исходного кода.

Пользователь в случае необходимости может дождаться выполнения асинхронной операции записи сообщения в базу, используя оператор then. Например:

 Ember.Logger.error('Текст сообщения об ошибке').then(result => {«действия после записи сообщения в БД»});

Кроме того, по завершении промиса инициируется событие с именем уровня ошибки. Например, ERROR, WARN и т.п. Обработчики событий с этими именами можно создать с использованием методов класса Evented.

ERROR — уровень ошибок

На уровень ERROR выводятся следующие сообщения об ошибках:

• все ошибки времени выполнения приложения, обрабатываемые хуком Ember.onerror;
• ошибки, формируемые методом Ember.Logger.error;
• ошибки, возникающие при обработке промисов при помощи обработки события error класса RSVP.Promise.

WARN — уровень предупреждений

На уровень WARN выводятся предупреждения, формируемые методом Ember.Logger.warn.

LOG — уровень логов

На уровень LOG выводятся сообщения, формируемые методом Ember.Logger.log.

INFO — уровень информационных сообщений

На уровень INFO выводятся информационные сообщения, формируемые методом Ember.Logger.info.

DEBUG — уровень отладочных сообщений
На уровень DEBUG выводятся отладочные сообщения, формируемые методом Ember.Logger.debug.

DEPRECATION — уровень сообщений о подозрительных и устаревших участках исходного кода
На уровень DEPRECATION выводятся предупреждения о подозрительных и устаревших участках исходного кода, формируемые методом Ember.Logger.warn, и включающие подстроку ‘DEPRECATION’.

Просмотр сообщений

Фреймворк Flexberry Ember включает в себя модель, а также роуты для отображени списковой формы и формы редактирования для логов.

Для подключения возможности просмотра записанных сообщений в приложение необходимо:

• добавить необходимый роут в роутер, объявленный в файле /app/router.js:

this.route('i-i-s-caseberry-logging-objects-application-log-l');

• добавить ссылку в свойство sitemap, объявленное в файле app/controllers/application.js для отображения соответствующего пункта меню:

{
  link: 'i-i-s-caseberry-logging-objects-application-log-l',
  caption: ...,
  title: ...,
  children: null
} 

По умолчанию на списке отображаются следующие столбцы:

• Время — время создания сообщения;
• Категория — ERROR, WARN, INFO, LOG, DEBUG, DEPRECATION;
• Сервер — DNS бэкенда;
• Браузер — информация о браузере, в котором было запущено клиентское приложение;
• URL — адрес страницы, с которой было инициировано логирование сообщения;
• Сообщение — текст сообщения.

На списковой форме отображения логов имеются две предопределенные пользовательские настройки, их можно увидеть в меню соответствующей формы (эти настройки определяют отображаемые по умолчанию столбцы и сортировку):

• Message
• FormattedMessage

По умолчанию используется предопределённая настройка Message.

При необходимости можно использовать предопределённую настройку FormattedMessage для отображения столбца Форматированное сообщение, в котором для сообщений уровня ERROR может содержаться имя файла, строка, стек вызовов, место возникновения ошибки.

Настройки логирования в файле конфигурации

Конфигурация сервиса логирования устанавливается в файле environment.js.

Пример настроек сервиса логирования в приложении Flexberry Ember представлены ниже.

'use strict';

module.exports = function(environment) {
  ...
  let ENV = {
    ...
    APP: {
      ...
      // Log service settings.
      log: {
        // Flag: indicates whether log service is enabled or not.
        enabled: true,

        storeErrorMessages: true,
        storeWarnMessages: false,
        storeLogMessages: true,
        storeInfoMessages: false,
        storeDebugMessages: false,
        storeDeprecationMessages: false,
        storePromiseErrors: true,
        showPromiseErrors: true,
        errorMessageFilterActive: false,
      }
    }
  };
  ...
  return ENV;
};

• enabled — флаг, определяющий, включён ли сервис логирования.
• storeErrorMessages, storeWarnMessages, storeLogMessages, storeInfoMessages, storeDebugMessages, storeDeprecationMessages, storePromiseErrors — флаги, определяющие, осуществлять ли запись сообщений соответствующего уровня в базу данных приложения,
• showPromiseErrors — флаг, определяющий, нужно ли вызывать исходный обработчик ошибок для промиса до записи соответствующего сообщения об ошибке в базу данных приложения,
• errorMessageFilterActive — флаг, определяющий, нужно ли применть фильтры логов, заданные в свойстве errorMessageFilters.

Настройки логирования в коде приложения

Разработчик может динамически включать и отключать сервис логирования с испоьзованием оператора:

this.get('logService').set('enabled', true);

Для динамического включения или отключения логирования на требуемом уровне используются операторы:

this.get('logService').set('storeErrorMessages', true) // уровень ошибок
this.get('logService').set('storeWarnMessages', true) // уровень предупреждений;
this.get('logService').set('storeLogMessages', true) // уровень логов;
this.get('logService').set('storeInfoMessages', true) // уровень информационных сообщений;
this.get('logService').set('storeDebugMessages', true) // уровень отладочных сообщений;
this.get('logService').set('storeDeprecationMessages', true) // уровень сообщений о подозрительных и устаревших участках исходного кода.
this.get('logService').set('storePromiseErrors', true) // уровень сообщений об ошибках промисов.

Для фильтрации сообщений, которые записываются в логи, можно использовать свойство errorMessageFilters, которое представляет собой массив объектов следующего вида:

{ category: 'PROMISE', message: 'TransitionAborted' }

В свойстве catrgory объекта указывается требуемый уровень логов, а в свойстве message — фраза, которая может встречаться в логируемом сообщении. При этом если логируемое сообщение содержит указанную фразу, а также имеет указанный уровень лога, то запись в базу данных приложения соответствующего сообщения выполняться не будет.