Анализиране на закъснения от лог файлове с помощта на 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 ms. Въпросите ми са следните:

  1. Как може това да бъде представено на графика в Kibana?
  2. Имаме разпределена архитектура, така че по всяка вероятност ще има catalina-exec-11 във втората инстанция и как може да се разграничи това от първата?
  3. Обобщете и двата сървъра, за да видите колко е било средното време за обработка на нишка.
  4. Как ще изглежда моят Grok филтър?

Ануп


person Anoop Gopalakrishnan    schedule 17.11.2014    source източник


Отговори (1)


Ако приемем, че можете да промените формата на регистрационните файлове, тези съвети може да са полезни за вас:

  1. Няма начин (доколкото знам) да се изчисли латентността на операция от два различни еластични документа за търсене в kibana 3.1 (текуща стабилна версия). Може би в Kibana 4 това ще бъде възможно. Това, което се опитвате да направите, би било тривиално, ако вашите записи в регистрационните файлове съдържат изминалото време на операцията. Например:

    2014-10-31 13:00:00,007 0 [catalina-exec-11] ОТСТРАНЯВАНЕ НА ГРЕШКИ [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, подобно на twitter снежинки. Използвайки такъв идентификатор, вашите регистрационни файлове ще изглеждат така:

    5892EAC3-EE95-4549-A787-CCE5A6639598 2014-10-31 13:00:00,007 0 [catalina-exec-11] ДЕГРЕШКА [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