Введение


В Badoo несколько десятков «самописных» демонов. Большинство из них написаны на Си, остался один на С++ и пять или шесть на Go. Они работают примерно на сотне серверов в четырех дата-центрах.

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



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

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

Выбор инструментов


Мы с самого начала отмели «облачные» системы, т.к. в Badoo принято не отдавать свои данные наружу, если это возможно. Проанализировав популярные инструменты, мы пришли к выводу, что, скорее всего, нам подойдет одна из трех систем:



Splunk


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



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

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

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

ELK: Elastic Search + Logstash + Kibana




Следующей в списке оказалась ELK. ELK — это, наверное, самая популярная на сегодняшний день система для сбора и анализа логов. И хочу сказать, что это неудивительно, т.к. она бесплатная, простая, гибкая и мощная.

ELK состоит из трех компонентов:
  • Elastic Search. Система хранения и поиска данных, основанная на «движке» Lucene;
  • Logstash. «Труба» с кучей фич, через которую данные (возможно, обработанные) попадают в Elastic Search;
  • Kibana. Веб-интерфейс для поиска и визуализации данных из Elastic Search.


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

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

Несмотря на то, что ELK нас полностью устраивала, был и третий претендент.

Graylog 2




В общем и целом Graylog 2 очень похожа на ELK: открытый код, легко устанавливать, тоже используется Elastic Search и может использоваться Logstash. Основное отличие в том, что Graylog 2 — система, готовая к использованию и «заточенная» конкретно на сбор логов. Своей готовностью для конечного пользователя она очень напоминаем Splunk. Здесь есть и удобный графический интерфейс с возможностью настраивать разбор строчек прямо в браузере, и ограничение доступа, и уведомления.

Но мы пришли к выводу, что ELK позволит нам сделать гораздо более гибкую систему, настроенную под наши нужды; позволит расширяться, менять компоненты. Как конструктор. Не понравилась одна часть — заменили на другую. Не хотели платить за watcher — сделали свою систему. Если в ELK все части легко можно снять и заменить, в Graylog 2 было ощущение, что какие-то части придется выдирать с корнем, а какие-то просто не получится внедрить.

Решено. Будем делать на ELK.

Доставка логов


На самом раннем этапе мы поставили обязательное требование, что логи должны и попадать в наш сборщик, и оставаться на диске. Система сбора и анализа логов — это хорошо, но любая система дает некоторую задержку, может выйти из строя и ничто не заменит тех возможностей, которые дают стандартные unix-утилиты типа grep, AWK, sort и т.д. У программиста должна остаться возможность зайти на сервер и посмотреть своими глазами, что там происходит.

Доставлять логи в Logstash мы могли следующим образом:
  • использовать имеющиеся утилиты из набора ELK (logstash-forwarder, а теперь уже beats). Они представляют из себя отдельный демон, который следит за файлом на диске и заливает его в Logstash;
  • использовать собственную разработку под именем LSD, которая у нас доставляет PHP-логи. По сути, это тоже отдельный демон, который следит за файлами с логами в файловой системе и заливает их куда-то. С одной стороны, в LSD были учтены и решены все проблемы, которые могут произойти при заливке огромного количества логов с огромного количества серверов, но система слишком «заточена» на PHP-скрипты. Нам бы пришлось ее доделывать;
  • параллельно с записью на диск записывать логи в стандартный для мира UNIX syslog.


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

Архитектура


Сервера и rsyslogd


Вместе с системными администраторами мы набросали архитектуру, которая показалась нам разумной: ставим один rsyslogd-демон на каждом сервере, один главный rsyslogd-демон на площадку, по одному Logstash на площадку и один кластер Elastic Search поближе к нам, к Москве, т.е. в пражский дата-центр.

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



Т.к. в Badoo кое-где используется docker, то мы планировали прокинуть сокет /dev/log внутрь контейнера встроенными средствами.

Итоговая схема была примерно такая:



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

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

Формат строчки лога и Logstash





Logstash — это труба для данных, в которую отправляются строчки. Внутри они парсятся и уходят в Elastic Search в виде готовых для индексирования полей и тегов.

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

Mar 04 04:00:14.609331 [NOTICE] <shard6> <16367> storage_file.c:1212 storage___update_dump_data(): starting dump (threaded, update)


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

В общей части мы видим дату, время с микросекундами, уровень лога, метку, PID, имя файла и номер строки в исходниках, имя функции. Самые обычные вещи.

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

Мы этот ident стандартизовали и передаем туда имя, вторичное имя и версию демона. К примеру meetmaker-ru.mlan-1.0.0. Таким образом мы можем отличить логи от разных демонов, от разных типов одного демона (например, страна, реплика) и иметь информацию о запущенной версии демона.

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

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

Упомяну про разбор времени. Мы постарались учесть разные варианты, и временем сообщения по умолчанию будет время из libangel-сообщения, т.е. по сути время, когда это сообщение было сгенерировано. Если по какой-то причине это время не было найдено, мы возьмем время от syslog, т.е. время, когда сообщение ушло в первый локальный syslog-демон. Если по какой-то причине и это время недоступно, временем сообщения будет время приема этого сообщения в Logstash.

Получившиеся поля идут в Elastic Search для индексации.



ElasticSearch


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

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

Мы выделили три сервера для кластера Elastic Search и настроили его так, чтобы каждый индекс имел одну реплику, как на схеме.



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

Кроме собственно отказоустойчивости, при такой схеме удобно делать обновление самого Elastic Search: останавливаем один из узлов, обновляем его, запускаем, обновляем другой.

То, что мы храним в Elastic Search именно логи, позволяет нам легко поделить все данные на индексы по дням. Такое разбиение дает несколько преимуществ:
  • в случае, если на серверах кончается место на диске, очень легко удалить старые данные. Это быстрая операция, и более того, для удаления старых данных есть готовый инструмент Curator;
  • во время поиска в интервале больше одного дня поиск можно вести параллельно. Более того, его можно вести параллельно как на одном сервере, так и на нескольких.


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

В настройке Elastic Search много тонкостей, связанных как с Java, так и просто с тем, что внутри используется Lucene. Но все эти тонкости описаны и в официальной документации, и в многочисленных статьях, поэтому я не буду углубляться. Кратко только упомяну, что на сервере Elastic Search нужно не забыть выделить память как под Java Heap, так и вне Heap (ее будет использовать Lucene), а также прописать «маппинги» конкретно для ваших полей в индексах, чтобы ускорить работу и уменьшить потребление места на диске.

Kibana


Тут говорить вообще не о чем :-) Поставили и работает. К счастью, в последней версии разработчики добавили возможность менять часовой пояс в настройках. Раньше по умолчанию брался локальный часовой пояс пользователя, что очень неудобно, т.к. у нас на серверах везде и всегда UTC, и мы привыкли общаться именно по нему.

Система уведомлений


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

В мире ELK нашлись два похожих готовых продукта:


Watcher — закрытый продукт от компании Elastic, требующий активную подписку. Elastalert — продукт open source, написаный на Python. Watcher мы отмели почти сразу по той же причине, что и раньше — закрытость и сложность расширения и адаптации под нас. Elastalert же по тестам показал себя классным продуктом, но и в нем было несколько минусов (впрочем, не очень критичных):
  • он написан на Python. Мы любим Python в качестве языка для написания быстрых «наколеночных» скриптов, но не очень хотим его видеть на продакшене в качестве конечного продукта;
  • возможности построения писем, которые система посылает в ответ на событие, совсем рудиментарны. А красота и удобство письма — это очень важно, если мы хотим, чтобы у других было желание пользоваться системой.


Поигравшись с Еlastalert и изучив его исходный код, мы решили написать продукт на PHP силами отдела платформы. В итоге Денис Карасик Battlecat за 2 недели написал «заточенный» под нас продукт: он интегрирован в backoffice и имеет только нужный функционал.





Для каждого правила система автоматически создает базовый dashboard в Kibana, ссылка на который будет в письме. При нажатии на ссылку вы увидите сообщения и график ровно за указанный в уведомлении промежуток времени.





«Грабли»


На этом этапе первый релиз системы был готов, работал и им можно было пользоваться. Но, как мы обещали, «грабли» не заставили себя ждать.

Проблема 1 (syslog + docker)


Стандартный способ общения между syslog-демоном и программой является unix socket /dev/log. Как говорилось выше, мы его пробросили внутрь контейнера стандартными средствами docker. Эта связка отлично работала до тех пор, пока нам не понадобилось перегрузить syslog-демон.

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

Если пробрасывать директорию целиком, то внутри без проблем может быть unix-сокет, и перезагрузка демона не нарушит ничего. Но тогда усложняется настройка всего этого богатства, ведь libc ожидает, что сокет находится в /dev/log.

Второй вариант, который мы рассматривали — использовать UDP или TCP для отправки логов наружу. Но тут такая же проблема, как и в предыдущем случае: libc умеет писать только в /dev/log. Нам бы пришлось писать свой syslog-клиент, а на данном этапе не хотелось этого делать.

В конце концов мы решили запустить по одному syslog-демону в каждом контейнере и продолжать писать в /dev/log стандартными libc функциями openlog()/syslog().

Это не было большой проблемой, т.к. наши системные администраторы все равно в каждом контейнере используют init-систему, а не запускают только один демон.

Проблема 2 (блокирующий syslog)


На devel-кластере мы заметили, что один из демонов периодически зависает. Включив внутренний watchdog демона, мы получили несколько backtrace, которые показывали, что демон зависает в syslog() -> write().

==== WATCHDOG ====
tag: IPC_SNAPSHOT_SYNC_STATE
start: 3991952 sec 50629335 nsec
now: 3991953 sec 50661797 nsec
Backtrace:
/lib64/libc.so.6(__send+0x79)[0x7f3163516069]
/lib64/libc.so.6(__vsyslog_chk+0x3ba)[0x7f3163510b8a]
/lib64/libc.so.6(syslog+0x8f)[0x7f3163510d8f]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(zlog1+0x225)[0x519bc5]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running[0x47bf7f]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(storage_save_sync_done+0x68)[0x47dce8]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(ipc_game_loop+0x7f9)[0x4ee159]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(game+0x25b)[0x4efeab]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(service_late_init+0x193)[0x48f8f3]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running(main+0x40a)[0x4743ea]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f3163451b05]
/local/meetmaker/bin/meetmaker-3.1.0_2782 | shard1: running[0x4751e1]
==== WATCHDOG ====


Быстренько скачав исходники libc и посмотрев на реализацию syslog-клиента, мы поняли, что функция syslog() синхронна и любые задержки на стороне rsyslog скажутся на демонах.

Что-то с этим нужно было делать, и чем скорее, тем лучше. Но мы не успели…

Через пару дней мы наступили на самые неприятные грабли современных архитектур — каскадный отказ.



Rsyslog по умолчанию настроен так, что если внутренняя очередь по какой-то причине заполняется, он начинает «троттлить» (англ. throttle), т.е. тормозить «запись в себя» новых сообщений.

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

А демоны, как я говорил выше, пишут в /dev/log синхронно и без какого-либо таймаута.
Результат предсказуем: из-за одного флудящего тестового демона тормозить начали все демоны, которые пишут в syslog хоть с какой-то значимой частотой.

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

Не мы одни наступали на эти грабли, оказывается. И даже не только с rsyslog. Синхронные вызовы в event loop демона — непозволительная роскошь.

Перед нами было несколько вариантов:
  • уходить от syslog. Возвращаться к одному из других вариантов, которые предполагают, что демон пишет на диск, а уже какой-то другой демон абсолютно независимо читает с диска;
  • продолжать писать в syslog синхронно, но в отдельном треде;
  • написать свой syslog-клиент и посылать данные в syslog по UDP.


Самым правильным вариантом, пожалуй, является первый. Но мы не хотели тратить время на него и быстро сделали третий, т.е. начали писать в syslog по UDP.

Что же касается Logstash, то все проблемы решили два параметра запуска: увеличение количества обработчиков и количества одновременно обрабатываемых строк (-w 24 -b 1250).

Планы на будущее


В ближайших планах сделать dashboard для наших демонов. Такой dashboard, который объединит в себе уже существующие и некоторые новые возможности:

  • просмотр работоспособности демона («светофор»), его базовой статистики;
  • графики количества строчек ERROR и WARNING в логах, их просмотр;
  • сработавшие правила системы оповещений;
  • SLA-мониторинг (мониторинг latency-ответов) с отображением проблемных сервисов или запросов;
  • выделение из логов демона различных этапов. Например, отметка о том, на каком этапе загрузки он находится, время загрузки, длительность каких-то периодичных процессов и т.п.


Наличие такого dashboard, по моему мнению, придется по вкусу и менеджерам, и программистам, и администраторам, и мониторщикам.

Заключение


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

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

Если говорить о нагрузке, то на данный момент в течение дня приходит от 600 до 2000 строчек с логами в секунду, с периодическими всплесками до 10 тысяч строчек. Данную нагрузку система переваривает без каких-либо проблем.



Размер дневного индекса варьируется от десятка до сотни гигабайт.



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

Марко Кевац, программист в отделе C/C++ разработки

Комментарии (47)


  1. QtRoS
    31.03.2016 16:39
    +1

    Хм, интересно, а почему именно C? Неужели не хватало производительности настолько?


    1. youROCK
      31.03.2016 16:47
      +1

      В основном это потребление памяти, нежели производительность. Но в целом производительность тоже важна.


      1. mkevac
        31.03.2016 16:55
        +1

        Да, Юра тоже прав. Если взять один из наших самых нагруженных сервисов, то суммарно на трех машинах он занимает в памяти около 1,3 TiB. Тщательное управление памятью в этом случае очень важно.


    1. mkevac
      31.03.2016 16:50
      +3

      Почему у нас больше всего демонов на Си?
      Вопрос многогранный.
      Во-первых, потому что мы хорошо знаем и любим Си.
      Во-вторых, Badoo существует давно и 10 лет назад было такого большого выбора вкусных языков, как Go или Rust.
      В третьих, у нас действительно очень высокая нагрузка. Мы, к примеру, в некоторых демонах используем JIT компиляцию для конвертации поискового запроса по битовому массиву в sse/avx/avx2 машинный код.
      Сейчас же, если нам не требуется супер высокой производительности, мы предпочитаем Go.


      1. QtRoS
        31.03.2016 19:05

        О, ну поскольку тема Go на хабре очень популярна, то позволю себе спросить — насколько просадка по сравнению с С?


        1. mkevac
          31.03.2016 19:15
          +5

          У меня нет для вас готовых цифр и красивых графиков до\после, к сожалению.
          Мы используем Go очень давно. На ранних этапах мы постоянно боролись с GC. Даже делали доклад на тему оптимизации Go на meetup, который проходил в нашем офисе. Но с каждой новой версией Go становится лучше и более приспособленным для высоких нагрузок и сервисов, которые используют много памяти.
          Если говорить про Си VS Go в плане производительности, то Go, конечно, проигрывает. Но Go на порядки удобнее для программирования. Делать многопоточную систему на Go — удовольствие, а на Си — морока. Если посмотреть чуть шире, то за счет этого удобства вы сможете написать распределенную систему на Go, которая будет работать лучше, чем система на Си. Не за счет банальной скорости, а за счет того что к моменту как система на Go уже будет вовсю работать и работать отлично, на Си вы будете искать ошибки в многопоточном коде.


        1. youROCK
          31.03.2016 22:59

          У нас в целом машины с демонами в процессор обычно не упираются. Но даже для случаев, когда CPU очень важен, никто не мешает использовать готовые библиотеки на Си, которые хорошо оптимизированы. Марко об этом не сказал, но вообще говоря у нас есть несколько демонов на го, которые именно так и делают. Например, используют RocksDB для хранения данных на диске, и при этом внутренние гошные структуры в качестве индекса и имеют много воркеров, которые с этими структурами как-то по-хитрому работают.


  1. Scratch
    31.03.2016 16:43
    +1

    Тоже используем ELK, правда доставляет всё logCourier, т.к. сервера в основном виндовые. А вы на riemann для алертинга не смотрели? Если не учитывать clojure и отсутствие кластерности, довольно мощная штука


    1. mkevac
      31.03.2016 17:41
      +1

      Нет, riemann мы пока не смотрели. Вы правы, clojure немного пугает. Но взглянуть стоит. Спасибо.


  1. billyevans
    31.03.2016 17:29

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

    http://engineeringblog.yelp.com/2015/11/introducing-paasta-an-open-platform-as-a-service.html


  1. xotey83
    31.03.2016 17:36
    +1

    Меня смущает строка «Мы выделили три сервера для кластера Elastic Search и настроили его так, чтобы каждый индекс имел одну реплику...»
    Вы реплицируете индекс целиком? Один шард на индекс?


    1. mkevac
      31.03.2016 17:39
      +1

      Верно. Один индекс = 1 шард + 1 реплика.
      Такое число мы выбрали сознательно, основываясь на документации, нашей задаче и некоторым статьям с рекомендациями в интернете.
      Один шард — это один Lucene индекс, а поиск по индексу должен затронуть все шарды. Т.е. если два разных шарда находятся на двух разных нодах, поиск затронет обе ноды. Т.к. у нас один индекс на день и он не супер-пупер большой, то мы посчитали правильным ускорить поиск за счет использования одного шарда.
      По вашему тону я могу судить что вы считаете это неправильным?


      1. xotey83
        31.03.2016 18:09
        +1

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


      1. xotey83
        31.03.2016 18:19

        Добавлю:
        Мы тоже используем ELK, тоже ES для хранения логов развернули на 3-х серверах. Но решили, использовать 3 мастер-шарда (по одному на каждую ноду) и одну реплику, подумав, что в случае вылета узла, recover индексов займёт меньше времени за счёт меньшего размера шардов.
        Спасибо за интересную статью!


      1. nucleusv
        05.04.2016 11:42

        При шардирование скорость обработки увеличивается, НО съедается место под словарь и управляющие структуры, так как он практически дублируется для каждого шарда.
        А при вашем подходе у вас активен только один сервер в день, при выделенных.
        Может 2 шарда на индекс + 1 реплика на шард.
        А почему вы не поставите haproxy перед 2-мя logstash?
        Основное отличие Graylog2 от Logstash, у него встроенный журнал Kafka, то есть сначала он пишет все в журнал, и только потом Elastic.


  1. Scf
    31.03.2016 18:42
    +1

    У вас есть многострочные логи? И если да, то как вы их пишете в syslog?


    1. mkevac
      31.03.2016 18:45
      +1

      Нет, у нас нет многострочных логов.


      1. pomme
        31.03.2016 21:37

        А как вы тогда обрабатываете лог ошибок со stack trace?


        1. mkevac
          31.03.2016 22:53

          Пока что стектрейсы не идут в syslog. В обозримом будущем мы или сделаем запись стректрейсов в виде одной строки или будем препроцессить их перед записью в сислог.


    1. Scratch
      31.03.2016 18:50
      +1

      если не в syslog, то logCourier и логсташ отлично справляются с многострочностью


      1. youROCK
        31.03.2016 22:54

        logCourier выглядит интересно. Неудивительно, ведь он на go :)


        1. mkevac
          31.03.2016 22:55

          Ты хочешь сказать что на Go не пишут плохих приложений? :-)


          1. youROCK
            31.03.2016 22:56

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


    1. ecto
      31.03.2016 19:30
      +1

      syslog формат принимает многострочные логи, если откурывать сокет в UDP формате


  1. grobbelaar
    31.03.2016 18:58
    +1

    Рассматривался ли fluentd для буфферизированной доставки логов?


    1. mkevac
      31.03.2016 19:04
      +1

      Нет, не рассматривали. У нас в данной задаче нет "зоопарка" разных систем, которые пишут логи. Собираются логи только наших самописных демонов, формат логов которых уже унифицирован.
      Т.е., как мне кажется, для данной конкретной задачи fluentd просто не нужен.


      1. grobbelaar
        31.03.2016 19:09
        +1

        я про проблему отложенной записи в централизованное хранилище минуя syslog, это решение могло бы подойти


        1. mkevac
          31.03.2016 19:16
          +1

          Да, наверное. Т.е. в ту же категорию "потенциальных замен" syslog, если с syslog будут проблемы. Спасибо.


  1. shandy
    31.03.2016 22:15
    +1

    Если говорить о нагрузке, то на данный момент в течение дня приходит от 600 до 2000 строчек с логами в секунду, с периодическими всплесками до 10 тысяч строчек. Данную нагрузку система переваривает без каких-либо проблем.

    А можно поинтересоваться мощностью ваших машин выделенных под ELK стек?


    1. mkevac
      31.03.2016 22:50
      +2

      Конечно. Если кратко, то такая спецификация:

      • Intel® Xeon® CPU E5-2680 0 @ 2.70GHz — 32 ядра
      • 64 GiB памяти
      • SSD диски


  1. Frank59
    01.04.2016 11:20

    Спасибо за статью. Тоже сейчас присматриваемся к ELK. Скажите, есть ли у вас в системе ситуации, когда один объект(запрос) проходит
    обработку в нескольких сервисах?
    Пример: пришел запрос от пользователя, он попадает сначала в сервис1, затем сервис1 в рамках обработки этого запроса обращается в сервис 2, сервис 2 лезет в сервис 3 и т.д.
    Если да, то отслеживаете ли вы в логах историю его обработку в разных сервисах и как у вас это реализовано(можно ли вытащить все логи из всех сервисов по этому запросу и понять, допустим, какой сервис тормозил)?


    1. mkevac
      01.04.2016 11:43

      У нас в Си отделе есть такие ситуации. Не так много, но есть. К примеру один узел кластера какого-либо сервиса может что-то спросить у другого узла или у под-сервиса. Но того, о чем вы говорите, у нас нет. Т.е. посмотреть что где тормозило можно только в большом масштабе, не по конкретному изначальному запросу. Но фича была бы классной, я согласен.


  1. bobgubko
    01.04.2016 11:31

    А почему лог за 26.03 почти на порядок больше, чем за последующие (27-29) дни?


    1. mkevac
      01.04.2016 11:31

      Какой-то из сервисов зафлудил сообщениями.


  1. velvetcat
    01.04.2016 11:31
    +2

    Имхо костыль на костыле:

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

    Синхронные вызовы в event loop демона — непозволительная роскошь

    Парни, ну это же азы...
    Но мы не хотели тратить время на него и быстро сделали третий, т.е. начали писать в syslog по UDP

    Зачем вообще нужны такие логи?


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


    1. mkevac
      01.04.2016 11:53
      +2

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

      Парни, ну это же азы...

      Конечно азы. Но вы будете удивлены сколько разных подводных камней зарыто в libc. Выделение памяти в snprintf, если вы используете %f или блокировки для получения таймзоны в localtime_r(). Или как у нас, блокирующая запись в syslog(). Такие вещи не лежат на поверхности. Легко говорить "ну что же вы так" постфактум.


      1. velvetcat
        01.04.2016 13:37
        +1

        если строить всю инфраструктуру с нуля и у вас нет большого кол-ва уже существующих и работающих сервисов.

        Во многих случаях верное, это замечание сейчас вообще не релевантно.
        Такие вещи не лежат на поверхности

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


        1. mkevac
          01.04.2016 13:51

          Во многих случаях верное, это замечание сейчас вообще не релевантно.

          Не согласен.
          Как вы вообще обходились без логов, если у вас допускаются такие вещи?

          У нас не допускаются такие вещи.


  1. acmnu
    01.04.2016 11:32
    +1

    Я правильно понял, что между локальными для физической машины rsyslog демоном и центральным демоном ЦОДа у вас был TCP? Ведь протокол syslog изначально подразумевает UDP.


    1. mkevac
      01.04.2016 11:45
      +1

      Скорее всего и сейчас между rsyslog-ами и сейчас идет tcp. На 100% не уверен. Возможно banuchka ответит.
      UDP у нас только от сервиса к rsyslogd. Не потому что нам там так нужны свойства UDP или не нужен оверхед TCP, а потому что посылку по UDP проще сделать асинхронной.


      1. acmnu
        01.04.2016 12:06
        +1

        Я к тому, что ваша проблема с каскадным отказом возможно решалась не написанием "собственного syslog по UDP", а просто переключением связи между главным демоном цода и демоном машины в UDP режим. Да, вы бы теряли логи, но не теряли стабильность. Честно говоря я ни разу не видел случая, что кто-нибудь включал TCP на передачу syslog в сети.


        1. mkevac
          01.04.2016 12:08
          +1

          Эта проблема была решена чуть по-другому. Наши администраторы настроили очереди в rsyslog правильно. До какого-то момента они в памяти, потом на диске, а потом новые сообщения выкидываются.


  1. acmnu
    01.04.2016 14:01
    +1

    При использовании UDP в качестве транспорта для событий есть одна мелочь, на которую я нарывался. Протокол syslog предполагает необязательность поля TIMESTAMP. В этом случае метку времени обычно проставляет принимающая сторона, но UDP может задержаться в пути и так как никакого контроля очередности (как в TCP) нет, то пакеты обработаются в другом порядке, что может сильно осложнить исследование логов. Поэтому приложение должно проставлять таймстамп при генерации события, а принимающая сторона не должна эти стампы игнорить (а есть соблазн так сделать, чтоб синхронизировать логи от разных источников). Оригинальный код libc проставляет время, но сторонние реализации могут на это забить, а зря.
    Вообще со временем в syslog засада. Поле таймстамп это просто текст. В этот текст должно вставляться смещение относительно GMT. Но на деле эта информация бывай кем-нибудь да дропится (особенно в собственных костылях), и в результирующий текстовый лог попадает локальное время клиента не пересчитаное во время принимающей стороны. Если у вас куча серверов работает в разных таймозонах тут вам придется походить по граблям. Ну или перевести все сервера в GMT (не всегда возможно, к сожалению).


    1. mkevac
      01.04.2016 18:41
      +1

      Тут нам проще. У нас есть время в оригинальном сообщении и мы везде и всегда используем UTC для времени.


  1. drdaeman
    01.04.2016 18:40

    Как я понимаю, ELK прекрасно решает задачи «показать крутой дэшборд полный графиков, чтобы сразу было видно общее здоровье систем» и «удобно и быстро посмотреть все сделанные записи по нужному критерию.» Но, скажите пожалуйста, а вот аналога классического tail -f вы на ELK не делали?
    Возможно это неправильный подход, но у меня еще есть привычка что когда прилетел алерт, условно говоря, «у нас что-то с гладилкой кота, кот уже 15 минут требует, но все еще неглаженный» то первый же порыв — сделать некое tail -f /var/log/pet.log | grep -w cat | grep -vi meow (за'grep'ав до состояния когда выделено только самое важное и активность логов приемлема для глаз), посмотреть что там такое прямо сейчас творится, а затем так и оставить на соседнем мониторе, чтобы краем глаза можно было именно что вживую наблюдать происходящие процессы и изменения в них.


    1. mkevac
      01.04.2016 18:42

      Мы так не делали и не делаем. Для tail заходим на конкретный сервер.
      Но я предполагаю что такое делать нужно не в ELK, а до него. Транспорт должен такое поддерживать.


    1. nucleusv
      05.04.2016 14:19

      Не вижу никаких проблем делать в Kibana в секции Discover: запрос по конкретному серверу + auto refresh 1 sec
      В Graylog 2 новом тоже сделали автообновлялку www.graylog.org/blog/50-announcing-graylog-v2-0-beta-1
      #Live taile