# Strang things happened when logstash grok the log message

**URL:** https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529
**Category:** Logstash
**Created:** [December 20, 2016, 6:57am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529 "2016-12-20T06:57:30Z")
**Posts on this page:** 8
**Page:** 1

<div class="post-metadata">

### Author: ![houfan](https://avatars.discourse-cdn.com/v4/letter/h/47e85d/32.png) [@houfan](https://discuss.elastic.co/u/houfan)
#### Post date: [December 20, 2016, 6:57am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/1 "2016-12-20T06:57:30Z")

</div>

I use filebeat-1.2.2 to monitor the mysql-slow.log.  
when I add two slow query records in it,

 ![](https://us1.discourse-cdn.com/elastic/original/2X/0/0042f0941d4a5a242388af97182ce8fefdd4861d.png)

and the logstash only give me one :

 ![](https://us1.discourse-cdn.com/elastic/original/2X/8/8a11d516ec40d1ed4164adf76d3a3bb08e249155.png)

😥 I do it again,adding two more records into the mysql-slow.log:

 ![](https://us1.discourse-cdn.com/elastic/original/2X/8/8d93c3f2301b8728298ba8edc3d308e0aaa86dc9.png)  
hehe....😂 just like the first time,logstash only give me one result:  
 ![](https://us1.discourse-cdn.com/elastic/original/2X/6/69dab248132c0cf608b0a805cc80a1685ab15e0b.png)  
👿 I tried the third time:  
 ![](https://us1.discourse-cdn.com/elastic/original/2X/d/d1568bf9e2e2beeca9ce23d22b821011e2244f30.png)  
and aha!!! 😂 this I got two results.I don't know why....  
 ![](https://us1.discourse-cdn.com/elastic/original/2X/4/4a5b1104d8136e5a0a6b28fd0a06b06630a50a15.png)

could you tell me why ? 😂  
really appreciate!!!

---

<div class="post-metadata">

### Author: ![houfan](https://avatars.discourse-cdn.com/v4/letter/h/47e85d/32.png) [@houfan](https://discuss.elastic.co/u/houfan)
#### Post date: [December 20, 2016, 7:03am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/2 "2016-12-20T07:03:06Z")

</div>

![](https://us1.discourse-cdn.com/elastic/original/2X/5/5a7fddff415e0508290e1bdb17ccab3446644941.png)  
this is my logstash.conf .

---

<div class="post-metadata">

### Author: ![magnusbaeck](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/magnusbaeck/32/44943_2.png) [@magnusbaeck](https://discuss.elastic.co/u/magnusbaeck)
#### Post date: [December 20, 2016, 7:25am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/3 "2016-12-20T07:25:03Z")

</div>

Please don't post screenshots. Use copy/paste.

---

<div class="post-metadata">

### Author: ![houfan](https://avatars.discourse-cdn.com/v4/letter/h/47e85d/32.png) [@houfan](https://discuss.elastic.co/u/houfan)
#### Post date: [December 20, 2016, 7:57am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/4 "2016-12-20T07:57:02Z")

</div>

😓 ok....

---

<div class="post-metadata">

### Author: ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)
#### Post date: [December 20, 2016, 4:23pm UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/5 "2016-12-20T16:23:57Z")

</div>

Do we presume you are using the Filebeat config from [here](https://discuss.elastic.co/t/problem-with-logstash-handling-the-mysql-slow-log/69531)

---

<div class="post-metadata">

### Author: ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)
#### Post date: [December 20, 2016, 4:27pm UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/6 "2016-12-20T16:27:25Z")

</div>

@houfan

You only get one event because the the second one's lines are being buffered internally - filebeat can only know when a previous set of lines is fully collected when the first line of the next set is seen.

---

<div class="post-metadata">

### Author: ![houfan](https://avatars.discourse-cdn.com/v4/letter/h/47e85d/32.png) [@houfan](https://discuss.elastic.co/u/houfan)
#### Post date: [December 21, 2016, 1:57am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/7 "2016-12-21T01:57:07Z")

</div>

after so many times I have tried,I figured out the reason is ：

> if [message] =~ "^# administrator" {  
> drop {}  
> }  
> if [message] =~ "^# Time" {  
> drop {}  
> }

this part didn't work right .It will drop much more messages than expect. cos when I delete this line

> # Time: 161214 11:32:21

and then logstash will give the correct two results.  
I add this grok pattern at the end :(?:# Time:.\*\n).

`> (?m)^# User@Host: %{USER:User}\[[^\]]+\] @ (?:(?<clienthost>\S*) )?\[(?:%{IP:Client_IP})?\]\s+Id:\s+%{NUMBER:row_id:int}\n# Schema: %{WORD:Schema}\s+Last_errno: %{NUMBER}\s+Killed: %{NUMBER}\n# Query_time: %{NUMBER:Query_Time:float}\s+Lock_time: %{NUMBER:Lock_Time:float}\s+Rows_sent: %{NUMBER:Rows_Sent:int}\s+Rows_examined: %{NUMBER:Rows_Examined:int}\s+Rows_affected: %{NUMBER:Rows_affected:int}\n(?:# Bytes_sent: %{NUMBER:Byte_sent:int}\n)+(?:use %{DATA:database};\s*\n)?SET\s+timestamp=%{NUMBER:timestamp};(?:\n)?(?<sql>(?<action>\w+)\b.*;)?(?:\n)?(?:# Time:.*\n)?`

logstash drop the first line “# Time: 161214 11:32:21”,and the whole messages (that the grok pattern matched )next.  
at the end logstash only give one result.

---

<div class="post-metadata">

### Author: ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)
#### Post date: [January 18, 2017, 1:57am UTC](https://discuss.elastic.co/t/strang-things-happened-when-logstash-grok-the-log-message/69529/8 "2017-01-18T01:57:12Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.