[译]你真的理解grok吗

时间  2019-12-07
标签 理解 grok 繁體版
原文   原文链接

Do you grok Grok?

原文： Do you grok Grok?

译者：neal1991css

welcome to star my articles-translator , providing you advanced articles translation. Any suggestion, please issue or contact mehtml

LICENSE: MITnode

grok (verb)

understand (something) intuitively or by empathy.git

解析日志数据时最多见的任务是将原始文本行分解为其余工具能够操做的一组结构化字段。 若是你使用 Elastic Stack，则能够利用 Elasticsearch 的聚合和 Kibana 的可视化，从日志中提取的信息（如 IP 地址，时间戳和特定域的数据）解释业务和操做问题。github

对于 Logstash，这个解构工做由 logstash-filter-grok 来承担，它是一个过滤器插件，能够帮助你描述日志格式的结构。正则表达式

这里有超过200个 grok 模式对于一些概念进行归纳，如IPv6 地址，UNIX 路径和月份名称。apache

为了以 grok 库匹配下列一行的格式，只须要将一些模式组合在一块儿：ruby

2016-09-19T18:19:00 [8.8.8.8:prd] DEBUG this is an example log message架构

%{TIMESTAMP_ISO8601:timestamp} \[%{IPV4:ip};%{WORD:environment}\] %{LOGLEVEL:log_level} %{GREEDYDATA:message}curl

这样就会生成结构化结果：

{
  "timestamp": "2016-09-19T18:19:00",

  "ip": "8.8.8.8",

  "environment": "prd",

  "log_level": "DEBUG",

  "message": "this is an example log message"

}

很简单，是否是？

是！

很棒！就到这了么？不！由于...

“我正在使用 grok 而且它很是慢”

这是一个很是广泛的说法！性能是一个常常从社区引起的话题，用户或客户一般会建立一个 grok 表达式，这将极大地减小 logstash 管道每秒处理的事件数量。

如前所述，grok 模式是正则表达式，所以这个插件的性能受到正则表达式引擎严重影响。 在接下来的章节中，咱们将提供一些关于建立 grok 表达式来匹配日志行的操做指南。

测量，测量，测量

为了在 grok 表达式设计过程当中验证决策和实验，咱们须要一种方法来快速测量两个或更多表达式之间的性能。 为此，我建立了一个小的 jruby 脚本，它直接使用logstash-filter-grok 插件，绕过 logstash 管道。

你能够从这获取脚本。咱们将使用它来收集性能数据来验证（或者推翻！）咱们的假设。

留意 grok 匹配失败时的性能影响

尽管知道 grok 模式与日志条目能够多快匹配很是重要，可是了解它在何时匹配失败也很重要。匹配成功和匹配失败的性能可能会差别很大。

当 grok 没法匹配一个事件的时候，它将会为这个事件添加一个 tag。默认这个 tag 是 _grokparsefailure。

Logstash 容许你将这些事件路由到能够统计和检查的地方。 例如，你能够将全部失败的匹配写入文件：

input { # ... }
filter {
  grok {
  match => { 
  "message" => "%{TIMESTAMP_ISO8601:timestamp} [%{IPV4:ip};%{WORD:environment}] %{LOGLEVEL:log_level} %{GREEDYDATA:message}" }
  }
}
output {
  if "_grokparsefailure" in [tags] {
    # write events that didn't match to a file
    file { "path" => "/tmp/grok_failures.txt" }
  } else {
     elasticsearch { }
  }
}

若是发现有多个模式匹配失败，则能够对这些行进行基准测试，并找出它们对管道吞吐量的影响。

如今咱们将使用 grok 表达式来解析 apache 日志行并研究其行为。 首先，咱们从一个示例日志条目开始：

220.181.108.96 - - [13/Jun/2015:21:14:28 +0000] "GET /blog/geekery/xvfb-firefox.html HTTP/1.1" 200 10975 "-" "Mozilla/5.0 (compatible; Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"

使用如下 grok 模式来匹配它：

%{IPORHOST:clientip} %{USER:ident} %{USER:auth} \[%{HTTPDATE:timestamp}\] "%{WORD:verb} %{DATA:request} HTTP/%{NUMBER:httpversion}" %{NUMBER:response:int} (?:-|%{NUMBER:bytes:int}) %{QS:referrer} %{QS:agent}

如今，咱们将比较成功匹配的匹配速度和不符合格式的其余三个日志条目，不管是在开始，中间仍是在行尾：

beginning mismatch - doesn't start with an IPORHOST

'tash-scale11x/css/fonts/Roboto-Regular.ttf HTTP/1.1" 200 41820 "http://semicomplete.com/presentations/logs'

middle mismatch - instead of an HTTP verb like GET or PUT there's the number 111

'220.181.108.96 - - [13/Jun/2015:21:14:28 +0000] "111 /blog/geekery/xvfb-firefox.html HTTP/1.1" 200 10975 "-" "Mozilla/5.0 (compatible; Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"'

end mismatch - the last element isn't a quoted string, but a number

'220.181.108.96 - - [13/Jun/2015:21:14:28 +0000] "GET /blog/geekery/xvfb-firefox.html HTTP/1.1" 200 10975 "-" 1'

这些日志行在文章开头提到的脚本进行基准测试，结果以下：

jndER.md.png

每秒匹配的日志数

咱们能够看到，对于这个 grok 表达式，取决于不匹配的位置，检查一行不匹配的时间可能比常规（成功）匹配慢6倍。 这有助于解释在行数不匹配时 grok 最大化 CPU 使用率的用户报告，如https://github.com/logstash-p...。

对此咱们能够作什么呢？

设置锚能够提高匹配失败的性能

既然如今咱们知道匹配失败对你的管道性能是很危险的，咱们须要修复它们。 在正则表达式设计中，你能够作的最好的事情来帮助正则表达式引擎是减小它须要作的猜想工做。 这就是为何一般会避免贪婪模式的缘由，可是咱们稍微回顾一下，由于有一个更简单的变化来改变模式的匹配。

让咱们回到咱们可爱的 apache 日志行...

220.181.108.96 - - [13/Jun/2015:21:14:28 +0000] "GET /blog/geekery/xvfb-firefox.html HTTP/1.1" 200 10975 "-" "Mozilla/5.0 (compatible; Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"

它由如下的 grok 模式来进行解析：

%{IPORHOST:clientip} %{USER:ident} %{USER:auth} \[%{HTTPDATE:timestamp}\] "%{WORD:verb} %{DATA:request} HTTP/%{NUMBER:httpversion}" %{NUMBER:response:int} (?:-|%{NUMBER:bytes:int}) %{QS:referrer} %{QS:agent}

因为grok插件的用户的天然指望，隐藏在表面上的性能问题显而易见：假设咱们编写的 grok 表达式仅从开始到结束与咱们的日志行匹配。 实际上，grok 被告知的是“在一行文本中找到这个元素序列”。

等一下，什么？就是它了，“在一行文本中”。这意味着好比一行数据...

OMG OMG OMG EXTRA INFORMATION 220.181.108.96 - - [13/Jun/2015:21:14:28 +0000] "GET /blog/geekery/xvfb-firefox.html HTTP/1.1" 200 10975 "-" "Mozilla/5.0 (compatible; Baiduspider/2.0; +http://www.baidu.com/search/spider.html)" OH LOOK EVEN MORE STUFF

将会依然匹配 grok 模式！好消息是修复很简单，咱们只须要添加一些锚！

锚容许你将正则表达式固定到字符串的某个位置。 经过在咱们的 grok 表达式中添加行锚点（^和$）的开始和结束，咱们确保咱们只会匹配整个字符串从开始到结束，而不包含其余的。

这在匹配失败的状况下很是重要。 若是锚点不在位，而且正则表达式引擎不能匹配一行日志，它将开始尝试在初始字符串的子字符串中查找该模式，所以咱们在上面看到了性能降低。

所以，为了看到性能影响，咱们产生一个新的使用锚的表达式与以前的表达式进行对比：

^%{IPORHOST:clientip} %{USER:ident} %{USER:auth} \[%{HTTPDATE:timestamp}\] "%{WORD:verb} %{DATA:request} HTTP/%{NUMBER:httpversion}" %{NUMBER:response:int} (?:-|%{NUMBER:bytes:int}) %{QS:referrer} %{QS:agent}$

下面是结果：

jncKe.md.png

对于不匹配的场景，这是一个至关显著的变化！ 不只咱们在中端和末端场景中消除了巨大的性能降低，并且使初始匹配失败检测速度提升了 10 倍左右。 赞。

留意两次匹配相同的行

你可能会说：“好吧，个人全部行都格式正确，因此咱们没有匹配失败”，但状况可能并不是如此。

随着时间的推移，咱们已经看到了 grok 用法的一个很是常见的模式，尤为是当来自多个应用程序的日志行经过单个网关（如 syslog）向全部消息添加公共头时。 举一个例子：假设咱们有三个使用“common_header：payload”格式的应用程序：

Application 1: '8.8.8.8 process-name[666]: a b 1 2 a lot of text at the end'

Application 2: '8.8.8.8 process-name[667]: a 1 2 3 a lot of text near the end;4'

Application 3: '8.8.8.8 process-name[421]: a completely different format | 1111'

一个常见的 grok 设置就是在一个 grok 中匹配三种格式：

grok {
  "match" => { "message => [
    '%{IPORHOST:clientip} %{DATA:process_name}\[%{NUMBER:process_id}\]: %{WORD:word_1} %{WORD:word_2} %{NUMBER:number_1} %{NUMBER:number_2} %{DATA:data}',
    '%{IPORHOST:clientip} %{DATA:process_name}\[%{NUMBER:process_id}\]: %{WORD:word_1} %{NUMBER:number_1} %{NUMBER:number_2} %{NUMBER:number_3} %{DATA:data};%{NUMBER:number_4}',
    '%{IPORHOST:clientip} %{DATA:process_name}\[%{NUMBER:process_id}\]: %{DATA:data} | %{NUMBER:number}'
    ] }
}

如今请注意，即便你的应用程序正确日志记录，grok 仍然会依次尝试将传入日志行与三个表达式进行匹配，从而在第一次匹配时中断。

这意味着确保咱们尽量快地跳到正确的位置仍然很重要，由于应用程序2老是有一个失败的匹配，应用程序3有两个失败的匹配。

咱们常常看到的第一个策略是对Grok匹配进行分层：首先匹配 header，覆盖 message 字段，而后仅匹配 bodies：

filter {
  grok {
    "match" => { "message" => '%{IPORHOST:clientip} %{DATA:process_name}\[%{NUMBER:process_id}\]: %{GREEDYDATA:message}' },
    "overwrite" => "message"
  }
  grok {
    "match" => { "message" => [
      '%{WORD:word_1} %{WORD:word_2} %{NUMBER:number_1} %{NUMBER:number_2} %{GREEDYDATA:data}',
      '%{WORD:word_1} %{NUMBER:number_1} %{NUMBER:number_2} %{NUMBER:number_3} %{DATA:data};%{NUMBER:number_4}',
      '%{DATA:data} | %{NUMBER:number}'
    ] }
  }
)

仅仅这一个就是一个有趣的性能提高，匹配行比初始方法快了2.5倍。 可是若是咱们添加咱们的同伴锚呢？

jnTxS.md.png

有意思！添加锚点使得两个架构的性能一样出色！ 事实上，因为失败的匹配性能大大提升，咱们最初的单杆设计稍微好一点，由于有一个比较少的匹配正在执行。

好的，那么咱们如何知道事情进行得如何？

咱们已经得出结论，监控“_grokparsefaiure”事件的存在是必不可少的，可是你能够作更多的事情：

自从版本 3.2.0 grok 插件，已经有不少设置能够帮助你何时事件须要花费长时间来匹配（或者失败匹配）。使用timeout millis 以及 timeout 标签可以对于 grok 匹配的时间设置一个上限。若是达到了限制时间，此次匹配就会被中断而且被打上 _groktimeout 标签。

使用咱们以前介绍的相同的条件策略，你·能够将这些事件重定向到 elasticsearch 中的文件或不一样的索引，以供往后分析。

另外一个很是酷的事情，咱们将在 Logstash 5.0 中引入度量的上下文是可以提取管道性能的数据，最重要的是，每一个插件的统计数据。 在 logstash 运行时，你能够查询其 AP I端点，并查看 logstash 在一个插件上花费的累积时间：

$ curl localhost:9600/_node/stats/pipeline?pretty | jq ".pipeline.plugins.filters"
[
  {
    "id": "grok_b61938f3833f9f89360b5fba6472be0ad51c3606-2",
    "events": {
      "duration_in_millis": 7,
      "in": 24,
      "out": 24
    },
    "failures": 24,
    "patterns_per_field": {
      "message": 1
    },
    "name": "grok"
  },
  {
    "id": "kv_b61938f3833f9f89360b5fba6472be0ad51c3606-3",
    "events": {
      "duration_in_millis": 2,
      "in": 24,
      "out": 24
    },
    "name": "kv"
  }
]

有了这些信息，你能够看到grok的“duration_in_millis”是否快速增加，若是失败的数量在增长，能够做为警告标志，代表某些模式设计很差，或者消耗的时间比预期的多。

总结

但愿这篇博文可以帮助你理解 grok 的行为，以及如何提升吞吐量。 总结咱们的结论：

  1. grok 匹配失败的时候性能可能表现很差。
  2. 监测发生 _grokfailures的状况而且对于他们的消耗进行基准测试。
  3. 使用锚好比 ^ 以及$ 避免歧义而且帮助正则引擎。
  4. 若是你不使用锚的话使用分层匹配会提升性能。若是怀疑的话，直接测量。
  5. 使用超时设置或者即将推出的 Metrics API 可以让你更好地了解 grok 是如何工做的，而且是性能分析的第一点。
相关文章
相关标签/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公众号
   欢迎关注本站公众号,获取更多信息
联系我们 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程