如何防止“超时执行 grok”和 _groktimeout 标记

Question

我有一个日志条目，其最后一部分会根据少数 HTTPS 条件不断变化。

示例日志：

INFO  [2021-09-27 23:07:58,632] [dw-1001 - POST /abc/api/v3/pqr/options] [386512709095023:] [ESC[36mUnicornClientESC[0;39m]: 
<"type": followed by 11000 characters including space words symbols <----- variable length.

grok 模式：

%{LOGLEVEL:loglevel}\s*\[%{TIMESTAMP_ISO8601:date}\]\s*\[%{GREEDYDATA:requestinfo}\]\s*\[%{GREEDYDATA:logging_id}\:%{GREEDYDATA:token}\]\s*\[(?<method>[^\]]+)\]\:\s*(?<messagebody>(.|\r|\n)*)

(.|\r|\n)*) 如果日志的可变部分很小，这可以正常工作，但是当遇到大日志时，它会抛出异常：

[2021-09-27T17:24:40,867][WARN ][logstash.filters.grok    ] Timeout executing grok '%{LOGLEVEL:loglevel}\s*\[%{TIMESTAMP_ISO8601:date}\]\s*\[%{GREEDYDATA:requestinfo}\]\s*\[%{GREEDYDATA:logging_id}\:%{GREEDYDATA:token}\]\s*\[(?<method>[^\]]+)\]\:\s*(?<messagebody>(.|\r|\n)*)' against field 'message' with value 'Value too large to output (178493 bytes)! First 255 chars are: INFO  [2021-09-27 11:50:14,005] [dw-398 - POST /xxxxx/api/v3/xxxxx/options] [e3acfd76-28a6-0000-0946-0c335230a57e:]

CPU 开始阻塞，持久队列增加并在 kibana 中滞后。有什么建议吗？

Answer 1

当模式匹配消息时，grok 和超时中的性能问题通常不是问题，当模式匹配失败时，它们是问题。

如果可能，首先要做的是锚定你的模式。 This blog post 有关于其有效性的性能数据。在您的情况下，当模式不匹配时， grok 将从行首开始查看 LOGLEVEL 是否匹配。如果不匹配，那么它将从该行的第二个字符开始并查看 LOGLEVEL 是否匹配。如果它一直不匹配，它将不得不进行数千次尝试来匹配该模式，这真的很昂贵。如果您将模式更改为以^%{LOGLEVEL:loglevel}\s*\[ 开头，那么 ^ 意味着 grok 只需在 [message] 的每一行开头评估与 LOGLEVEL 的匹配。如果您将其更改为 "\A%{LOGLEVEL:loglevel}\s*\[，那么它只会在 [message] 字段的开头评估匹配。

其次，如果可能，请避免使用 GREEDYDATA，除非在模式的末尾。当将 10 KB 字符串与具有多个 GREEDYDATA 的模式匹配时，如果模式不匹配，则每个 GREEDYDATA 将针对数千个不同的子字符串进行尝试，导致为每个事件进行数百万次匹配尝试（这不是那么简单，但不匹配确实会变得非常昂贵）。尝试将 GREEDYDATA 更​​改为 DATA，如果仍然有效，请保留它。

第三，如果可能，将 GREEDYDATA/DATA 替换为自定义模式。例如，在我看来\[%{GREEDYDATA:requestinfo}\] 可以替换为\[(?<requestinfo>[^\]]+)，我希望在整体模式不匹配时更便宜。

第四，我会认真考虑使用 dissect 而不是 grok

dissect { mapping => { "message" => "%{loglevel->} [%{date}] [%{requestinfo}] [%{logging_id}:%{token}] [%{method}]: %{messagebody}" } }

但是，在解析过滤器中有一个bug，如果在映射中使用“->”，则单个分隔符不匹配，需要多个分隔符。因此%{loglevel->} 将匹配INFO [2021，但不匹配ERROR [2021。我经常这样做

mutate { gsub => [ "message", "\s+", " " ] }

并删除-> 以解决此问题。 dissect 远不如 grok 灵活和强大，这使得它便宜得多。请注意， dissect 将创建空字段，例如启用 keep_empty_captures 的 grok，因此您将获得一个包含该消息的“”的 [token] 字段。