摘要：允許你將這些事件路由到可以統(tǒng)計(jì)和檢查的地方。實(shí)際上，被告知的是在一行文本中找到這個(gè)元素序列。總結(jié)希望這篇博文能夠幫助你理解的行為，以及如何提高吞吐量。監(jiān)測(cè)發(fā)生的情況并且對(duì)于他們的消耗進(jìn)行基準(zhǔn)測(cè)試。如果懷疑的話，直接測(cè)量。

原文：Do you grok Grok?
譯者：neal1991
welcome to star my articles-translator , providing you advanced articles translation. Any suggestion, please issue or contact me
LICENSE: MIT

grok (verb) 
understand (something) intuitively or by empathy.

解析日志數(shù)據(jù)時(shí)最常見的任務(wù)是將原始文本行分解為其他工具可以操作的一組結(jié)構(gòu)化字段。 如果你使用 Elastic Stack，則可以利用 Elasticsearch 的聚合和 Kibana 的可視化，從日志中提取的信息（如 IP 地址，時(shí)間戳和特定域的數(shù)據(jù)）解釋業(yè)務(wù)和操作問(wèn)題。

對(duì)于 Logstash，這個(gè)解構(gòu)工作由 logstash-filter-grok 來(lái)承擔(dān)，它是一個(gè)過(guò)濾器插件，可以幫助你描述日志格式的結(jié)構(gòu)。

這里有超過(guò)200個(gè) grok 模式對(duì)于一些概念進(jìn)行概括，如IPv6 地址，UNIX 路徑和月份名稱。

為了以 grok 庫(kù)匹配下列一行的格式，只需要將一些模式組合在一起：

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}

這樣就會(huì)生成結(jié)構(gòu)化結(jié)果：

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

  "ip": "8.8.8.8",

  "environment": "prd",

  "log_level": "DEBUG",

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

}

很簡(jiǎn)單，是不是？

是！

很棒！就到這了么？不！因?yàn)?..

這是一個(gè)非常普遍的說(shuō)法！性能是一個(gè)經(jīng)常從社區(qū)引發(fā)的話題，用戶或客戶通常會(huì)創(chuàng)建一個(gè) grok 表達(dá)式，這將極大地減少 logstash 管道每秒處理的事件數(shù)量。

如前所述，grok 模式是正則表達(dá)式，因此這個(gè)插件的性能受到正則表達(dá)式引擎嚴(yán)重影響。 在接下來(lái)的章節(jié)中，我們將提供一些關(guān)于創(chuàng)建 grok 表達(dá)式來(lái)匹配日志行的操作指南。

為了在 grok 表達(dá)式設(shè)計(jì)過(guò)程中驗(yàn)證決策和實(shí)驗(yàn)，我們需要一種方法來(lái)快速測(cè)量?jī)蓚€(gè)或更多表達(dá)式之間的性能。 為此，我創(chuàng)建了一個(gè)小的 jruby 腳本，它直接使用logstash-filter-grok 插件，繞過(guò) logstash 管道。

你可以從這獲取腳本。我們將使用它來(lái)收集性能數(shù)據(jù)來(lái)驗(yàn)證（或者推翻！）我們的假設(shè)。

盡管知道 grok 模式與日志條目可以多快匹配非常重要，但是了解它在什么時(shí)候匹配失敗也很重要。匹配成功和匹配失敗的性能可能會(huì)差異很大。

當(dāng) grok 無(wú)法匹配一個(gè)事件的時(shí)候，它將會(huì)為這個(gè)事件添加一個(gè) tag。默認(rèn)這個(gè) tag 是 _grokparsefailure。

Logstash 允許你將這些事件路由到可以統(tǒng)計(jì)和檢查的地方。 例如，你可以將所有失敗的匹配寫入文件：

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 { }
  }
}

如果發(fā)現(xiàn)有多個(gè)模式匹配失敗，則可以對(duì)這些行進(jìn)行基準(zhǔn)測(cè)試，并找出它們對(duì)管道吞吐量的影響。

現(xiàn)在我們將使用 grok 表達(dá)式來(lái)解析 apache 日志行并研究其行為。 首先，我們從一個(gè)示例日志條目開始：

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 模式來(lái)匹配它：

%{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}

現(xiàn)在，我們將比較成功匹配的匹配速度和不符合格式的其他三個(gè)日志條目，無(wú)論是在開始，中間還是在行尾：

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"

這些日志行在文章開頭提到的腳本進(jìn)行基準(zhǔn)測(cè)試，結(jié)果如下：

每秒匹配的日志數(shù)

我們可以看到，對(duì)于這個(gè) grok 表達(dá)式，取決于不匹配的位置，檢查一行不匹配的時(shí)間可能比常規(guī)（成功）匹配慢6倍。 這有助于解釋在行數(shù)不匹配時(shí) grok 最大化 CPU 使用率的用戶報(bào)告，如https://github.com/logstash-p...。

對(duì)此我們可以做什么呢？

既然現(xiàn)在我們知道匹配失敗對(duì)你的管道性能是很危險(xiǎn)的，我們需要修復(fù)它們。 在正則表達(dá)式設(shè)計(jì)中，你可以做的最好的事情來(lái)幫助正則表達(dá)式引擎是減少它需要做的猜測(cè)工作。 這就是為什么通常會(huì)避免貪婪模式的原因，但是我們稍微回顧一下，因?yàn)橛幸粋€(gè)更簡(jiǎn)單的變化來(lái)改變模式的匹配。

讓我們回到我們可愛的 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 模式來(lái)進(jìn)行解析：

%{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插件的用戶的自然期望，隱藏在表面上的性能問(wèn)題顯而易見：假設(shè)我們編寫的 grok 表達(dá)式僅從開始到結(jié)束與我們的日志行匹配。 實(shí)際上，grok 被告知的是“在一行文本中找到這個(gè)元素序列”。

等一下，什么？就是它了，“在一行文本中”。這意味著比如一行數(shù)據(jù)...

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

將會(huì)依然匹配 grok 模式！好消息是修復(fù)很簡(jiǎn)單，我們只需要添加一些錨！

錨允許你將正則表達(dá)式固定到字符串的某個(gè)位置。 通過(guò)在我們的 grok 表達(dá)式中添加行錨點(diǎn)（^和$）的開始和結(jié)束，我們確保我們只會(huì)匹配整個(gè)字符串從開始到結(jié)束，而不包含其他的。

這在匹配失敗的情況下非常重要。 如果錨點(diǎn)不在位，并且正則表達(dá)式引擎不能匹配一行日志，它將開始嘗試在初始字符串的子字符串中查找該模式，因此我們?cè)谏厦婵吹搅诵阅芟陆怠?/p>

因此，為了看到性能影響，我們產(chǎn)生一個(gè)新的使用錨的表達(dá)式與之前的表達(dá)式進(jìn)行對(duì)比：

^%{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}$

下面是結(jié)果：

對(duì)于不匹配的場(chǎng)景，這是一個(gè)相當(dāng)顯著的變化！ 不僅我們?cè)谥卸撕湍┒藞?chǎng)景中消除了巨大的性能下降，而且使初始匹配失敗檢測(cè)速度提高了 10 倍左右。 贊。

你可能會(huì)說(shuō)：“好吧，我的所有行都格式正確，所以我們沒(méi)有匹配失敗”，但情況可能并非如此。

隨著時(shí)間的推移，我們已經(jīng)看到了 grok 用法的一個(gè)非常常見的模式，尤其是當(dāng)來(lái)自多個(gè)應(yīng)用程序的日志行通過(guò)單個(gè)網(wǎng)關(guān)（如 syslog）向所有消息添加公共頭時(shí)。 舉一個(gè)例子：假設(shè)我們有三個(gè)使用“common_header：payload”格式的應(yīng)用程序：

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"

一個(gè)常見的 grok 設(shè)置就是在一個(gè) 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}"
    ] }
}

現(xiàn)在請(qǐng)注意，即使你的應(yīng)用程序正確日志記錄，grok 仍然會(huì)依次嘗試將傳入日志行與三個(gè)表達(dá)式進(jìn)行匹配，從而在第一次匹配時(shí)中斷。

這意味著確保我們盡可能快地跳到正確的位置仍然很重要，因?yàn)閼?yīng)用程序2總是有一個(gè)失敗的匹配，應(yīng)用程序3有兩個(gè)失敗的匹配。

我們經(jīng)常看到的第一個(gè)策略是對(duì)Grok匹配進(jìn)行分層：首先匹配 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}"
    ] }
  }
)

僅僅這一個(gè)就是一個(gè)有趣的性能提升，匹配行比初始方法快了2.5倍。 但是如果我們添加我們的同伴錨呢？

有意思！添加錨點(diǎn)使得兩個(gè)架構(gòu)的性能同樣出色！ 事實(shí)上，由于失敗的匹配性能大大提高，我們最初的單桿設(shè)計(jì)稍微好一點(diǎn)，因?yàn)橛幸粋€(gè)比較少的匹配正在執(zhí)行。

我們已經(jīng)得出結(jié)論，監(jiān)控“_grokparsefaiure”事件的存在是必不可少的，但是你可以做更多的事情：

自從版本 3.2.0 grok 插件，已經(jīng)有很多設(shè)置可以幫助你什么時(shí)候事件需要花費(fèi)長(zhǎng)時(shí)間來(lái)匹配（或者失敗匹配）。使用timeout millis 以及 timeout 標(biāo)簽?zāi)軌驅(qū)τ?grok 匹配的時(shí)間設(shè)置一個(gè)上限。如果達(dá)到了限制時(shí)間，這次匹配就會(huì)被中斷并且被打上 _groktimeout 標(biāo)簽。

使用我們之前介紹的相同的條件策略，你·可以將這些事件重定向到 elasticsearch 中的文件或不同的索引，以供日后分析。

另一個(gè)非常酷的事情，我們將在 Logstash 5.0 中引入度量的上下文是能夠提取管道性能的數(shù)據(jù)，最重要的是，每個(gè)插件的統(tǒng)計(jì)數(shù)據(jù)。 在 logstash 運(yùn)行時(shí)，你可以查詢其 AP I端點(diǎn)，并查看 logstash 在一個(gè)插件上花費(fèi)的累積時(shí)間：

$ 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”是否快速增長(zhǎng)，如果失敗的數(shù)量在增加，可以作為警告標(biāo)志，表明某些模式設(shè)計(jì)不好，或者消耗的時(shí)間比預(yù)期的多。

希望這篇博文能夠幫助你理解 grok 的行為，以及如何提高吞吐量。 總結(jié)我們的結(jié)論：

grok 匹配失敗的時(shí)候性能可能表現(xiàn)不好。

監(jiān)測(cè)發(fā)生 _grokfailures的情況并且對(duì)于他們的消耗進(jìn)行基準(zhǔn)測(cè)試。

使用錨比如 ^ 以及$ 避免歧義并且?guī)椭齽t引擎。

如果你不使用錨的話使用分層匹配會(huì)提高性能。如果懷疑的話，直接測(cè)量。

使用超時(shí)設(shè)置或者即將推出的 Metrics API 能夠讓你更好地了解 grok 是如何工作的，并且是性能分析的第一點(diǎn)。