Анализ задержек из лог-файлов с помощью logstash и kibana

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

2014-10-31 13:00:00,007 [catalina-exec-11] DEBUG [com.clairmail.jms.concurrent.poolimpl.JMSProducerPoolImpl] Providing a pooled producer to catalina-exec-11

..... а также

2014-10-31 13:00:00,121 [catalina-exec-11] DEBUG [com.clairmail.jms.concurrent.poolimpl.JMSProducerPoolImpl] catalina-exec-11 has returned producer to pool.

Из приведенных выше журналов я могу понять, что этот конкретный поток catalina-exec-11 занял около 107 мс. Мои вопросы следующие:

  1. Как это можно представить на графике в Kibana?
  2. У нас распределенная архитектура, поэтому, по всей вероятности, во втором экземпляре будет catalina-exec-11, и как его можно отличить от первого экземпляра?
  3. Агрегируйте данные по обоим серверам, чтобы узнать, каково среднее время обработки потока.
  4. Как будет выглядеть мой фильтр Grok?

Ануп


logstash kibana logstash-grok elasticsearch
person Anoop Gopalakrishnan    schedule 17.11.2014    source источник

Ответы (1)


arrow_upward
1
arrow_downward

Если вы можете изменить формат журналов, вам могут быть полезны следующие советы:

  1. Невозможно (насколько я знаю) вычислить задержку операции из двух разных эластичных поисковых документов в kibana 3.1 (текущая стабильная версия). Возможно, в Kibana 4 это будет возможно. То, что вы пытаетесь сделать, было бы тривиальным, если бы ваши записи в журналах содержали прошедшее время операции. Например:

    2014-10-31 13:00:00,007 0 [catalina-exec-11] DEBUG [com.clairmail.jms.concurrent.poolimpl.JMSProducerPoolImpl] Предоставление объединенного производителя для catalina-exec-11

    2014-10-31 13:00:00,121 114 [catalina-exec-11] DEBUG [com.clairmail.jms.concurrent.poolimpl.JMSProducerPoolImpl] catalina-exec-11 вернул производителя в пул.

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

  1. Итак, у вас есть распределенная архитектура с разными машинами и, возможно, именованными потоками. Вам нужен глобально уникальный идентификатор контекста запроса. Есть много способов добиться этого: Guid или уникальный числовой идентификатор Int64, аналогичный твиттеру snowflakes. Используя такой идентификатор, ваши журналы будут выглядеть так:

    5892EAC3-EE95-4549-A787-CCE5A6639598 2014-10-31 13:00:00,007 0 [catalina-exec-11] DEBUG [com.clairmail.jms.concurrent.poolimpl.JMSProducerPoolImpl] Предоставление объединенного производителя для catalina-exec- 11

    5892EAC3-EE95-4549-A787-CCE5A6639598 2014-10-31 13:00:00,121 114 [catalina-exec-11] DEBUG [com.clairmail.jms.concurrent.poolimpl.JMSProducerPoolImpl] catalina-exec-11 вернул производителя в бассейн.

Обратите внимание, что я добавил новое поле guid в начале каждой записи журнала.

  1. Это легко может быть достигнуто с помощью logstash. Если logstash настроен на чтение файлов журналов с разных компьютеров, ввод файла добавит новое поле «хост» в событие logstash, которое вы можете отправить в elasticsearch. Затем на панели инструментов kibana вы можете легко показать, как запросы распределяются между разными машинами.

  2. ваш фильтр grok может выглядеть примерно так: grok { match => [ "message", "%{UUID:requestid}%{SPACE}%{TIMESTAMP_ISO8601:timestamp}%{SPACE}%{NUMBER:ellapsedmilliseconds}%{SPACE} [{WORD:threadname}]%{SPACE}%{WORD:level}%{SPACE}[%{WORD:logger}]%{SPACE}%{WORD:logmessage}"] }

Это всего лишь пример, и вам придется настроить его под свои нужды.

Надеюсь, это поможет.

person Roman    schedule 17.11.2014
comment
Спасибо, Роман, очень помогает. Я надеюсь, что Kibana 4 поставляется с поддержкой расчета прошедшего времени. - person Anoop Gopalakrishnan; 26.11.2014