我想弄清楚为什么logstash收到的一些消息有一些文本从他们丢失。
我从Untangle NGFW(11.0 – 许可)发送日志到logstash,以便我可以保留网页filter日志的历史logging等。
我首先注意到在创buildsyslog之后不久,Untangle的日志就出现了一个问题,我设置了一个filter来查找那些已经被拆分的消息,因为它们太长了,这个filter将它们连接在一起,这样grok&json就可以parsing它们logstash中的parsing器。 大多数事件处理都很好,包括大多数带有多行标记的事件,但是也有一些消息通过jsonparsefailure标记传递。 我复制这些消息,并把它们放到一个JSONparsing器,发现他们将失败,因为信息拆分后不久的短信部分丢失。
当我第一次看到这个问题的时候,我的想法是我的filter做了一些意想不到的事情,但是我检查了一下,逻辑上看不出它会如何删除随机丢失的文本。 然后我从logstashconfiguration中删除了所有filter,并检查了正在进入的消息,有些仍然缺less一些文本。 我在#logstash IRC频道询问了这个问题,并且有人build议在进入时克隆所有的消息,这将允许我继续过滤所有的消息,但会保持原始消息不变。 然后我可以检查接收到的消息与保存在解开日志文件中的消息。 我还向Untangle提出了一个支持查询,他提出了一个bugzilla,这个bugzilla比不可复制的时间晚了一些。
我从logstash的configuration:
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" ] } } }
一个缺less文本的示例事件,这是从克隆的消息文件中获取的:
{"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机器上保存的内容包括完整的消息,包括从日志loggingangular度所缺less的字符。 我知道这不是通过Untangle的rsyslog发送的,因为日志条目前面缺less优先级。 但是这应该是发送之前由rsyslog读取的消息。
我需要知道的是,我现在怎么弄清楚这个pipe道在什么地方坏了,Untangle机器上的信息是完整的,但是在logstash服务器上接收和保存信息的时候,缺less一些字符。
我非常有信心,唯一发生这种情况的是消息被发送方分割,我根本没有任何问题。 这种情况经常发生在拆分的消息上,但是并不是每一次,我都能从不同的消息中得到3个例子,这些消息在拆分后不久就会丢失字符,在一个相当安静的服务器上大约15分钟(目前正在testing这个新的Untangle机器推出生产)。
我曾经想过设置一个tcpdump来捕获所有的stream量从解开服务器到logstash,我可以做的很好,但我不确定我将如何find我正在寻找的PCAP文件中的消息来certificate发送的信息与/丢失的字符丢失。
我正在使用rsyslogd 5.8.11和logstash 1.5.0RC2(我正在使用1.4.2,但更新,因为克隆 – >filter不工作在1.4.2)
任何build议如何最好地调查这个,所以我可以find问题的原因将不胜感激。
编辑:
今天我已经做了一些进一步的调查,我做了一个数据包捕获,然后在一个事件发生之后通过捕获去了一些文本。 我发现服务器收到的数据包中缺less文本,所以我认为这个问题与rsyslog有关。 我也发现,rsyslog不会做分裂(据我所知)似乎是由logging器完成的。