Статьи

Logstash — важна последовательность блоков Grok

Март 21, 2018

Вступление

Logstash — это один из популярных инструментов с открытым исходным кодом, используемый для анализа журналов приложений. Он обычно поставляется с двумя другими инструментами, а именно Elasticsearch и Kibana, для формирования стека ELK.

Недавно я анализировал некоторые данные из журнала приложения. Пример журнала показан ниже.

2015-04-17 16:23:21,581 - DEBUG - [process16] sample.vo.RemoteApplicationEntityVO - Bean is null.
2015-04-17 16:23:29,296 - DEBUG - [processor4] sample.filter.AuthorizationFilter - User james authorized to access: printReport
2015-04-17 16:24:25,997 - DEBUG - [processor1] sample.entity.RemoteContext - Removing remote application entity.
2015-04-17 16:24:25,997 - DEBUG - [processor1] sample.entity.RemoteContext - sample.vo.RemoteApplicationEntityVO@xxys345
2015-04-17 16:24:25,997 - ERROR - [processor1] sample.entity.RemoteContext - Exception in setStorageFailureEnabled
java.lang.NullPointerException
	at sample.entity.RemoteContext.setStorageEnabled(RemoteContext.java:627)
	at sample.entity.RemoteContext.removeArchiveEntity(RemoteContext.java:496)
	at sample.entity.RemoteContext.removeEntity(RemoteContext.java:459)
	at sample.struts.PrintReport.execute(PrintReportAction.java:136)
2015-04-17 16:32:03,805 - ERROR - [processor5] sample.ArchiveContext - Exception validating remote archive admin
java.rmi.ConnectException: Connection refused to host: 127.0.0.1; nested exception is: 
	java.net.ConnectException: Connection refused
	at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:128)
	. . .
	at sample.struts.SearchAction.execute(SearchAction.java:246)
Caused by: java.net.ConnectException: Connection refused
	at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:56)
	... 42 more
2015-04-19 13:57:45,046 - DEBUG - [processor5] sample.struts.LoginAction - User Logging in: jenny
2015-04-19 13:57:45,046 - DEBUG - [processor5] sample.struts.LoginAction - Creating a login request for: jenny
2015-04-19 13:57:45,760 - ERROR - [processor5] sample.struts.LoginAction - User credential invalid - User jenny password is incorrect

Разбор данных

Для разбора этих данных я изначально использовал следующий шаблон в сценарии Logstash. Оператор grok, который применяет этот шаблон, также добавляет поле с именем «subType», которое можно использовать во время аналитики и создания отчетов. Я называю этот шаблон «лог».

match => { "message" => "%{TOMCAT_DATESTAMP:logTimeString}%{SPACE}-%{SPACE}%{LOGLEVEL:level}%{SPACE}-%{SPACE}\[%{CUSTOM_PROCESS_NAME:processName}\]%{SPACE}%{JAVACLASS:class}%{SPACE}-%{SPACE}%{JAVALOGMESSAGE:logmessage}" }

Для входных данных, соответствующих этому шаблону, Logstash создает запись JSON, как показано ниже.

{
  "message" => "2015-04-17 16:32:03,805 - ERROR - [processor5] sample.ArchiveContext - Exception validating remote archive admin ",
  "@version" => "1",
  "@timestamp" => "2015-05-05T10:06:37.075Z",
  "host" => "127.0.0.1:63036",
  "type" => "webadmin_log",
  "tags" => [],
  "logTimeString" => "2015-04-17 16:32:03,805",
  "level" => "ERROR",
  "processName" => "processor5",
  "class" => " sample.ArchiveContext ",
  "logmessage" => "Exception validating remote archive admin ",
  "subType" => "log",
  "logTime" => "2015-04-17T11:02:03.805Z"
}

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

Целью синтаксического анализа является не только преобразование обычного текста в более подходящий формат, но также попытка пометить его, чтобы мы могли выполнить значимый анализ и отчетность на более позднем этапе. Используя Logstash, это возможно с помощью нескольких шаблонов и различать входные данные с помощью подходящих маркеров во входных данных. В этом примере последняя строка ввода указывает причину сбоя при входе пользователя. Если эту строку можно пометить отдельно, можно легко создать отчет, в котором перечислены все неправильные попытки входа в систему за день, неделю или месяц. Если строка помечена с использованием общего тега ‘log’, потребуется дополнительная бизнес-логика, чтобы просмотреть проанализированные данные и определить те строки, которые относятся к неудаче попытки входа в систему. Для облегчения воспоминаний я реплицирую последние две строки из данных образца.

BUG - [processor5] sample.struts.LoginAction - Creating a login request for: jenny
2015-04-19 13:57:45,760 - ERROR - [processor5] sample.struts.LoginAction - User credential invalid - User jenny password is incorrect

Использование нескольких шаблонов

Для разбора ввода я решил использовать другой шаблон для последней строки ввода. Определенный мной шаблон показан ниже. Я называю эту модель «учетными данными».

match => { "message" => "%{TOMCAT_DATESTAMP:logTimeString}%{SPACE}-%{SPACE}%{LOGLEVEL:level}%{SPACE}-%{SPACE}\[%{CUSTOM_PROCESS_NAME:processName}\]%{SPACE}%{JAVACLASS:class}%{SPACE}-%{SPACE}%{CUSTOM_TEXT_DATA:textData}%{SPACE}-%{SPACE}%{JAVALOGMESSAGE:logmessage}" }

Поле «subType» в этом случае получает значение «credential» в соответствующем блоке grok. Затем я поместил этот шаблон после шаблона ‘log’ (со значением ‘subType’ в качестве ‘log’). При выполнении я ожидал увидеть запись со значением «subType» как «учетные данные». К моему удивлению, все записи имели значение «subType» как «log». Причиной такого поведения была последовательность блоков grok в скрипте Logstash.

As Logstash executes the statements in the ‘filter’ block in a top-down manner for each line of input, it was matching the input with the first pattern it encountered. This happened because the two patterns are very similar and the first pattern also successfully matches the last line from the sample. If the second pattern is not placed inside a ‘_grokparsefailure’ check, Logstash will happily match the last line from the sample with the second pattern as well. This will result in a record that contains duplicate values for many fields, namely logTimeString, logTime, class, processName and subType. Generating reports from such records is problematic. A sample record is shown below. Hence, each pattern is enclosed in a ‘_grokparsefailure’ condition check, which ensures that Logstash applies a pattern only if the previous pattern does not match the input data.
{
  "message" => "2015-04-19 13:57:45,760 - ERROR - [processor5] sample.struts.LoginAction - User credential invalid - User jenny password is incorrect",
  "@version" => "1",
  "@timestamp" => "2015-05-05T10:22:29.234Z",
  "host" => "127.0.0.1:62462",
  "type" => "webadmin_log",
  "logTimeString" => [ [0] "2015-04-19 13:57:45,760", [1] "2015-04-19 13:57:45,760"],
  "level" => [ [0] "ERROR", [1] "ERROR"],
  "processName" => [ [0] "processor5", [1] "processor5"    ],
  "class" => [ [0] "sample.struts.LoginAction", [1] "sample.struts.LoginAction"],
  "textData" => "User credential invalid ",
  "logmessage" => [ [0] "User jenny password is incorrect", [1] "User credential invalid - User jenny password is incorrect"],
  "subType" => [ [0] "credential", [1] "log"],
  "logTime" => "2015-04-19T08:27:45.760Z"
}

Поскольку шаблон ‘log’ был более общим, он сопоставлялся даже с теми входными строками, которые я хотел сопоставить, используя шаблон ‘credential’. Поэтому мне пришлось изменить последовательность сопоставления с образцом. Мне пришлось поставить проверку шаблона «учетные данные» перед проверкой шаблона «журнал». После этого изменения выход Logstash был в соответствии с ожиданиями. Окончательный скрипт Logstash приведен ниже.

input {
  tcp {
    type => "webadmin_log"
    port => 9999
  }
}
filter {
  if [type] == "webadmin_log" {
    # user credential invalid
    grok {
      patterns_dir => "./patterns"
      match => { "message" => "%{TOMCAT_DATESTAMP:logTimeString}%{SPACE}-%{SPACE}%{LOGLEVEL:level}%{SPACE}-%{SPACE}\[%{CUSTOM_PROCESS_NAME:processName}\]%{SPACE}%{JAVACLASS:class}%{SPACE}-%{SPACE}%{CUSTOM_TEXT_DATA:textData}%{SPACE}-%{SPACE}%{JAVALOGMESSAGE:logmessage}" }
      add_field => { "subType" => "credential" }
    }
    # other log lines
    if "_grokparsefailure" in [tags] {
      grok {
        patterns_dir => "./patterns"
        match => { "message" => "%{TOMCAT_DATESTAMP:logTimeString}%{SPACE}-%{SPACE}%{LOGLEVEL:level}%{SPACE}-%{SPACE}\[%{CUSTOM_PROCESS_NAME:processName}\]%{SPACE}%{JAVACLASS:class}%{SPACE}-%{SPACE}%{JAVALOGMESSAGE:logmessage}" }
        add_field => { "subType" => "log" }
        remove_tag => ["_grokparsefailure"]
      }
  }
		
  if "_grokparsefailure" not in [tags] {
    date {
      locale => "en"
      match => ["logTimeString", "YYYY-MM-dd HH:mm:ss,SSS"]
      #timezone => "Asia/Calcutta"
      target => "logTime"
    }
  }
}
output {
  if "_grokparsefailure" not in [tags] {
      stdout {
      codec => "rubydebug"
    }
  }
}

Вывод

Хотя такие инструменты, как Logstash, упрощают и упрощают анализ журналов приложений и преобразование простого текста в структурированные документы, первостепенное значение имеет анализ входных данных для создания правильной структуры документа. Если документы не заполнены правильными значениями, мы столкнемся с проблемами на этапах анализа и отчетности. Для более точного контроля на этапах аналитики и отчетности нам может потребоваться указать шаблоны Grost Logstash, которые позволят нам классифицировать входные данные. При этом нам нужно убедиться, что строка ввода соответствует одному и только одному шаблону в скрипте. Кроме того, нам нужно упорядочить последовательность шаблонов Грока таким образом, чтобы пробовать более конкретные шаблоны, прежде чем применять более общие шаблоны к входным данным.

Таким образом, при анализе данных важен не только шаблон, но и последовательность шаблонов, примененных к входным данным.

54
Share: