我试图弄清楚为什么 logstash 收到的一些消息缺少一些文本。
我正在将日志从 Untangle NGFW（11.0 - 许可）发送到 logstash，以便我可以保留 Web 过滤器日志等的历史记录。
我第一次注意到来自 Untangle 的日志存在问题是在设置 syslog 后不久，我设置了一个过滤器，用于查找因太长而被拆分的消息，然后将它们重新组合在一起，以便可以通过 grok 和 logstash 中的 json 解析器进行解析。大多数事件处理正常，包括大多数带有多行标签的事件，但是许多消息也带有 jsonparsefailure 标签。我复制了这些消息并将它们放入 json 解析器中，发现它们会失败，因为消息拆分后不久消息的一小部分丢失了。
我第一次看到这个问题时的想法是我的过滤器做了一些意想不到的事情，但我仔细检查了一下，逻辑上看不出它如何删除随机丢失的任何文本。然后我从 logstash 配置中删除了所有过滤器，并检查了收到的消息，有些仍然缺少一些文本。我在 #logstash IRC 频道中询问了这个问题，有人建议克隆所有收到的消息，这样我就可以继续过滤所有消息，但原始消息会保持完整。然后我可以根据 untangle 日志文件中保存的内容检查收到的消息。我还向 Untangle 提出了支持查询，他们提出了一个 bugzilla，该 bugzilla 在当天晚些时候关闭，因为无法重现。
我的 logstash 配置如下：
input {
tcp {
port => 15005
type => "untangle-syslog"
}
}
filter {
#looks for messages from untangle input, then clones every one, some to be saved in a file for future reference, some to be proces
sed by following filters
if [type] == "untangle-syslog" {
clone {
#"cant_touch_this" will be saved to file "modify_this" will be filtered below
clones => [ "cant_touch_this", "modify_this" ]
}
}
if [type] == "modify_this" {
#look for any lines that end with ... this would be a multiline message split by rsyslog when untangle NGFW sends the message
multiline {
pattern => "\.\.\.$"
what => "next"
}
#remove the part between the ... delimiters with nothing, this should return the message to it's starting format
if "multiline" in [tags] {
mutate {
gsub => [ "message", "\.\.\.\n.*\.\.\.", "" ]
}
}
grok {
match => { "message" => "<%{POSINT:priority}>%{SYSLOGTIMESTAMP:syslogtimestamp} localhost node-17: \[SyslogManagerImpl\] <(?:%
{WORD:Protocol}|)> %{WORD:Severity}\s*uvm\[0\]:\s*%{GREEDYDATA:jsonmessage}" }
add_tag => "untangle-syslog"
tag_on_failure => "untangle_syslog_grok_failure"
}
mutate {
gsub => [ "jsonmessage", '"host"', '"websiteHost"' ]
}
json {
source => "jsonmessage"
}
date {
match => [ "timeStamp", "yyyy-MM-dd HH:mm:ss.SSS" ]
}
}
}
缺少文本的示例事件，取自克隆的消息文件：
{"message":"<142>Apr 7 11:01:52 localhost node-17: [SyslogManagerImpl] <TCP93307337353045> INFO uvm[0]: {\"requestUri\":\"/pixel.gif?e=34&ud=0&up=0&qa=1366&qb=768&qc=0&qd=0&qf=1366&qe=643&qh=1349&qg=1652&qi=1366&qj=728&qk=0&ql=%3B%5BpwxnRd%7Dt%3Aa%5DmJVOG)%2C~%405%2F%5BGI%3Fi64CE)4b%3DhSIpIm%7C%7CXIN%26JZFEYooWU!%5BFZKU37xWzi%2BGr1VsEkeSKx%26aRo.)%3FJX%5E%255uA%5D%5BC%2BQVo7X%3Ch%2CeI%7C9x%5ELmFLBJIbEBE)8%25S%40xN~ReUobxEsct!6AMCaUw_N%5BoUz%2FAbi%5DpRAJa%3Ci6ikhMn%3CRRHj%5BG%2B1ck9Ln%3AA.eqRB4%2530980o(I%7DY(T0cC%236%3AOtNCp%2F%5B*bT1(ADac8.KG%26JaybqP%23Y%25a%2FqujM37rYgq%7B!%3Dy3mG%2BQV77zANVitbKxpwoFKL3l9EU%22y%2F.D%5BIAby)rx(%40J%3A%3AsLeLG)%3B.o%5DE%24d!L2HyXLy!%7DbSqVB4%25S%40%5EXYq4%3Cc3%2B%7BE%24C%23XGmuGTtDZF%5Eh...","@version":"1","@timestamp":"2015-04-07T10:01:54.569Z","host":"10.0.0.1","type":"cant_touch_this"}
{"message":"<142>Apr 7 11:01:52 localhost ...\"pixel.moatads.com\",\"timeStam \"2015-04-07 11:01:52.447\",\"sessionId\":93307337353045,\"requestId\":93307337050879,\"tag\":\"uvm[0]: \",\"class\":\"class com.untangle.node.http.HttpRequestEvent\",\"method\":\"GET\",\"sessionEvent\":{\"protocol\":6,\"timeStamp\":\"2015-04-07 11:01:52.356\",\"SClientAddr\":\"/192.168.1.11\",\"tag\":\"uvm[0]: \",\"CServerAddr\":\"/54.237.114.13\",\"protocolName\":\"TCP\",\"CClientAddr\":\"/10.0.248.31\",\"class\":\"class com.untangle.uvm.node.SessionEvent\",\"hostname\":\"10.0.248.31\",\"SClientPort\":38237,\"serverIntf\":1,\"CServerPort\":80,\"username\":\"USER\",\"clientIntf\":2,\"sessionId\":93307337353045,\"policyId\":14,\"SServerPort\":80,\"SServerAddr\":\"/54.237.114.13\",\"CClientPort\":22810},\"contentLength\":0}","@version":"1","@timestamp":"2015-04-07T10:01:54.570Z","host":"10.0.0.1","type":"cant_touch_this"}
正如您在第二行看到的，timeStam 已被截断，单词的结尾消失了，结束的 \" 和 也消失了：
然后我连接到 Untangle 服务器并检查日志以查看那里保存了什么：
Apr 7 11:01:52 localhost node-17: [SyslogManagerImpl] <TCP93307337353045> INFO uvm[0]: {"requestUri":"/pixel.gif?e=34&ud=0&up=0&qa=1366&qb=768&qc=0&qd=0&qf=1366&qe=643&qh=1349&qg=1652&qi=1366&qj=728&qk=0&ql=%3B%5BpwxnRd%7Dt%3Aa%5DmJVOG)%2C~%405%2F%5BGI%3Fi64CE)4b%3DhSIpIm%7C%7CXIN%26JZFEYooWU!%5BFZKU37xWzi%2BGr1VsEkeSKx%26aRo.)%3FJX%5E%255uA%5D%5BC%2BQVo7X%3Ch%2CeI%7C9x%5ELmFLBJIbEBE)8%25S%40xN~ReUobxEsct!6AMCaUw_N%5BoUz%2FAbi%5DpRAJa%3Ci6ikhMn%3CRRHj%5BG%2B1ck9Ln%3AA.eqRB4%2530980o(I%7DY(T0cC%236%3AOtNCp%2F%5B*bT1(ADac8.KG%26JaybqP%23Y%25a%2FqujM37rYgq%7B!%3Dy3mG%2BQV77zANVitbKxpwoFKL3l9EU%22y%2F.D%5BIAby)rx(%40J%3A%3AsLeLG)%3B.o%5DE%24d!L2HyXLy!%7DbSqVB4%25S%40%5EXYq4%3Cc3%2B%7BE%24C%23XGmuGTtDZF%5Eh...
Apr 7 11:01:52 localhost ..."pixel.moatads.com","timeStamp": "2015-04-07 11:01:52.447","sessionId":93307337353045,"requestId":93307337050879,"tag":"uvm[0]: ","class":"class com.untangle.node.http.HttpRequestEvent","method":"GET","sessionEvent":{"protocol":6,"timeStamp":"2015-04-07 11:01:52.356","SClientAddr":"/192.168.1.11","tag":"uvm[0]: ","CServerAddr":"/54.237.114.13","protocolName":"TCP","CClientAddr":"/10.0.248.31","class":"class com.untangle.uvm.node.SessionEvent","hostname":"10.0.248.31","SClientPort":38237,"serverIntf":1,"CServerPort":80,"username":"USER","clientIntf":2,"sessionId":93307337353045,"policyId":14,"SServerPort":80,"SServerAddr":"/54.237.114.13","CClientPort":22810},"contentLength":0}
Untangle 机器上保存的内容包括完整消息，包括从 logstashes 的角度来看缺失的字符。我知道这不是 Untangle 通过 rsyslog 发送的内容，因为日志条目前面缺少优先级。然而，这应该是 rsyslog 在发送之前读取的消息。
我需要知道的是，现在如何找出这个管道发生故障的地方，消息在 Untangle 机器上开始时是完整的，但是在 logstash 服务器接收和保存消息时，消息缺少一些字符。
我非常确信这种情况只会在发送方拆分消息时发生，单行消息完全没有问题。拆分消息时经常发生这种情况，但并非每次都是这样，我设法从不同的消息中获取了 3 个示例，这些示例在拆分后不久就缺少字符，在相当安静的服务器上大约 15 分钟内完成（目前正在测试这台新的 Untangle 机器，然后投入生产）。
我曾经考虑过设置一个 tcpdump 来捕获从 untangle 服务器到 logstash 的所有流量，我可以做得很好，但我不确定如何在 PCAP 文件中找到我正在寻找的消息以证明发送的信息带有/不带有丢失的字符。
我正在使用 rsyslogd 5.8.11 和 logstash 1.5.0RC2（我之前使用的是 1.4.2，但已更新，因为克隆->过滤器在 1.4.2 中不起作用）
如果您能提供任何关于如何最好地调查此事的建议以便我能找到问题的原因，我将不胜感激。
编辑：
今天我做了进一步的调查，我进行了数据包捕获，然后在事件发生后检查了捕获的内容，发现缺少一些文本。我发现服务器收到的数据包中缺少文本，所以我相信问题出在 rsyslog 上。我还发现 rsyslog 不进行拆分（据我所知），这似乎是由记录器完成的。