# Logstash consuming CPU usage over 100%

**URL:** <https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084>\
**Category:** Logstash\
**Created:** [August 3, 2016, 9:21am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084 "2016-08-03T09:21:13Z")\
**Posts on this page:** 12\
**Page:** 1

<div class="post-metadata">

**Author:** ![YuWatanabe](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yuwatanabe/32/13259_2.png) [@YuWatanabe](https://discuss.elastic.co/u/YuWatanabe)\
**Post date:** [August 3, 2016, 9:21am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/1 "2016-08-03T09:21:13Z")

</div>

Hi!

I would like ask question about logstash plugin.

I am now using logstash but looks like it is consuming high CPU usage.

![](https://us1.discourse-cdn.com/elastic/original/2X/4/4e2094ec86132411fae9536a66e92f3b9242e125.PNG)

Below is part of lines from my config.

```
input {
  file {
    path => ["/var/log/logstash/data/test/test1/*/always/*"]
    start_position => "beginning"
    codec => multiline {
      pattern => "----------------------\+|Present Rot \[360deg\]|Total Rot \[360deg\] "
      negate => false
      what => previous
    }
    ignore_older => 31104000

    tags => ["arm"]
  }
}

output {
  if "RIGHT HAND" in [tags] or "LEFT HAND" in [tags] {
    elasticsearch {
      hosts => ["127.0.0.1"]
      index => "test-%{+YYYY.MM.dd}"
      document_type => "arm"
    }
    stdout { codec => rubydebug }
    
  }
}

filter {
# Set the date 
  if [message] =~ "\*\*\* \d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} \*\*\*" {
    grok {
      match => { 
        "message" => "\*\*\* (?<date>\d{4}-\d{2}-\d{2}) \d{2}:\d{2}:\d{2} \*\*\*" 
      }
    }

    ruby {
      init => "
        @@date = ''
      "
      code => "
        @@date = event.get('date')
      "
    }
  }

#########################################################
# Filter stanza for arm parsing
#########################################################
  if "arm" in [tags] and "multiline" in [tags] {
    # Set tags for right or left arm
    if [message] =~ ".*RIGHT HAND.*" {
      mutate {
        add_tag => ["RIGHT HAND"]
      }
    } else if [message] =~ ".*LEFT HAND.*" {
      mutate {
        add_tag => ["LEFT HAND"]
      }
    }

    if "RIGHT HAND" in [tags] or "LEFT HAND" in [tags] {
      # Parsing comes first
      grok {
        # Parse the parts values
        match => {
          "message" => ".*\[(?<logged_time>\d{2}:\d{2}:\d{2})\.\d{6}\]\s+Total\s+Rot\s+\[360deg\]\s+\|\s+(?<f11_val>\d+)\|\s+(?<f12_val>\d+)\|\s+(?<f13_val>\d+)\|\s+(?<f21_val>\d+)\|\s+(?<f22_val>\d+)\|\s+(?<f23_val>\d+)\|\s+(?<f31_val>\d+)\|\s+(?<f32_val>\d+)\|\s+(?<f33_val>\d+)\|\s+(?<f41_val>\d+)\|\s+(?<f42_val>\d+)\|\s+(?<f51_val>\d+)\|\s+(?<f52_val>\d+).*"
        }

        # Create a new field to split
        add_field => {
          "arm_parts_and_val" => "f11_%{f11_val},f12_%{f12_val},f13_%{f13_val},f21_%{f21_val},f22_%{f22_val},f23_%{f23_val},f31_%{f31_val},f32_%{f32_val},f33_%{f33_val},f41_%{f41_val},f42_%{f42_val},f51_%{f51_val},f52_%{f52_val}"
        }

        # Remove unnecessary fields
        remove_field => [
          "message" ,
          "f11_val" ,
          "f12_val" , 
          "f13_val" , 
          "f21_val" , 
          "f22_val" , 
          "f23_val" , 
          "f31_val" , 
          "f32_val" , 
          "f33_val" , 
          "f41_val" , 
          "f42_val" , 
          "f51_val" , 
          "f52_val" 
        ]
      }

      # Next split the event
      split { 
        # Tell the split plugin for which field to split
        field => "arm_parts_and_val"

        # Define the terminator . Comma in this case
        terminator => ","

        # Define a new field to set the new values
        target => "new_arm_parts_and_val"
      }

      # Grok again to split the "new_arm_parts_and_val"
      grok {
        # Split "new_arm_parts_and_val" into parts name and value
        match => {
          "new_arm_parts_and_val" => "(?<parts_name>\w\d+)_(?<total_rot>\d+)"
        }

        # Remove rest of fields
        remove_field => [
          "arm_parts_and_val",
          "new_arm_parts_and_val"
        ]
      }

```

I am considering to tune the config file but not sure where to start from.  
Is there a know issue that any of the plugin consumes high cpu usage?

Thanks,  
Yu Watanabe

---

<div class="post-metadata">

**Author:** ![purbon](https://avatars.discourse-cdn.com/v4/letter/p/edb3f5/32.png) [@purbon](https://discuss.elastic.co/u/purbon)\
**Post date:** [August 3, 2016, 11:15am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/2 "2016-08-03T11:15:22Z")

</div>

HI,  
First I would recommend doing a bit of profiling, to do it you could take a few thread dumps and see where the cost is, one very good article on this tools is [http://www.ibm.com/developerworks/library/j-5things8/](http://www.ibm.com/developerworks/library/j-5things8/) for example.

However with your config, If I had to have one suspicion, here for high cpu performance would it be the multiline codec, so that would be my first hypothesis.

When you get this data if you share we can sort of the offender and sort out the problem more in deep.

PD: Knowing how your multiline files looks like would it also be necessary and helpful.

- purbon

---

<div class="post-metadata">

**Author:** ![YuWatanabe](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yuwatanabe/32/13259_2.png) [@YuWatanabe](https://discuss.elastic.co/u/YuWatanabe)\
**Post date:** [August 3, 2016, 11:22am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/3 "2016-08-03T11:22:22Z")

</div>

Hi @purbon

I will take a look at **jstack** and see if I find anything.

I have a below format in my log.

```
[10:47:33.068415] RIGHT |A|B|C|D|E|F|G|H|I|J|K|L|L|
[10:47:33.068415] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+
[10:47:33.068415] test1 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068415] test2 | 1| 2| 3| 4| 5| 6| 7| 8| 9| 10| 11| 12| 13|
[10:47:33.068415] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+
[10:47:33.068415] test3 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068540] test4 | 1| 2| 3| 4| 5| 6| 7| 8| 9| 10| 11| 12| 13|
[10:47:33.068540] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+
[10:47:33.068540] test5 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068540] test6 | 0| 0| 0| 0| 0| 1| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068540] ======================+=======+=======+=======+=======+=======+=======+=======+=======+=======+=======+=======+=======+=======+
[10:47:33.068540] LEFT |A|B|C|D|E|F|G|H|I|J|K|L|L|
[10:47:33.068540] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+
[10:47:33.068540] test1 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068540] test2 | 1| 2| 3| 4| 5| 6| 7| 8| 9| 10| 11| 12| 13|
[10:47:33.068540] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+
[10:47:33.068540] test3 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068540] test4 | 1| 2| 3| 4| 5| 6| 7| 8| 9| 10| 11| 12| 13|
[10:47:33.068540] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+
[10:47:33.068540] test5 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068665] test6 | 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
[10:47:33.068665] ----------------------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+-------+

```

I am using the multiline codec to parse line test1 of RIGHT HAND and line test1 of LEFT HAND.

---

<div class="post-metadata">

**Author:** ![purbon](https://avatars.discourse-cdn.com/v4/letter/p/edb3f5/32.png) [@purbon](https://discuss.elastic.co/u/purbon)\
**Post date:** [August 3, 2016, 12:00pm UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/4 "2016-08-03T12:00:14Z")

</div>

Is your log with or without the timestamp part? I don't see this in the pattern, so might be one reason to it might get nuts, will debug a bit more and report here if I find the reason.

---

<div class="post-metadata">

**Author:** ![YuWatanabe](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yuwatanabe/32/13259_2.png) [@YuWatanabe](https://discuss.elastic.co/u/YuWatanabe)\
**Post date:** [August 3, 2016, 1:51pm UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/5 "2016-08-03T13:51:18Z")

</div>

@purbon

Thanks for the reply.  
Each line includes a **time**. **Date** is logged in another line. But I this **date and time** in a different field **logged\_time**.

@timestamp is filled with the datetime which is automatically generated by logstash.

---

<div class="post-metadata">

**Author:** ![YuWatanabe](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yuwatanabe/32/13259_2.png) [@YuWatanabe](https://discuss.elastic.co/u/YuWatanabe)\
**Post date:** [August 4, 2016, 9:09am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/6 "2016-08-04T09:09:14Z")

</div>

@purbon  
I just found that filebeat also support multiline.

I will check the performance with filebeat.

---

<div class="post-metadata">

**Author:** ![purbon](https://avatars.discourse-cdn.com/v4/letter/p/edb3f5/32.png) [@purbon](https://discuss.elastic.co/u/purbon)\
**Post date:** [August 4, 2016, 11:51am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/7 "2016-08-04T11:51:33Z")

</div>

yeah, my overall recommendation would be to do multiline at filebeat level, is usually easier.

---

<div class="post-metadata">

**Author:** ![YuWatanabe](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yuwatanabe/32/13259_2.png) [@YuWatanabe](https://discuss.elastic.co/u/YuWatanabe)\
**Post date:** [August 4, 2016, 12:46pm UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/8 "2016-08-04T12:46:22Z")

</div>

I merged the multiline process to **filebeat**.  
It looks like CPU usage of is flowing at around 100% and filebeat is at around 60%.

 ![](https://us1.discourse-cdn.com/elastic/original/2X/5/5cfac491a9c643bcc8078e27b3305cc067cf81ce.PNG)

---

<div class="post-metadata">

**Author:** ![purbon](https://avatars.discourse-cdn.com/v4/letter/p/edb3f5/32.png) [@purbon](https://discuss.elastic.co/u/purbon)\
**Post date:** [August 9, 2016, 11:46am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/9 "2016-08-09T11:46:32Z")

</div>

Hi,  
my suspicion here is the pattern to do the multiline is not working, are you able to see any output at all using a simple config like:

```auto
input {
  beats { .... }
}

output {
  stdout { codec => rubydebug }
}

```

---

<div class="post-metadata">

**Author:** ![YuWatanabe](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yuwatanabe/32/13259_2.png) [@YuWatanabe](https://discuss.elastic.co/u/YuWatanabe)\
**Post date:** [August 10, 2016, 1:13am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/10 "2016-08-10T01:13:58Z")

</div>

Hello @purbon

Yes.

Multiline in beats is working perfectly and I was able to see events in output plugin (stdout and elasticsearch).

However, I still do not know which module in filter plugin is causing the high cpu usage though.

---

<div class="post-metadata">

**Author:** ![purbon](https://avatars.discourse-cdn.com/v4/letter/p/edb3f5/32.png) [@purbon](https://discuss.elastic.co/u/purbon)\
**Post date:** [August 10, 2016, 6:12am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/11 "2016-08-10T06:12:03Z")

</div>

> [@YuWatanabe](#):
>
> I will take a look at jstack and see if I find anything.

After we discarded all other situations, so is definitely an issue with the filters. Can you share here a few thread dumps and/or the jstack output. We're looking to get an impression which threads are running, so we can spot the filter causing this high cpu usage. I see you use a lot of grok who can be one of the reasons of this behaviour, but we'll need this information to move forward.

- purbon

---

<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:** [July 6, 2017, 4:44am UTC](https://discuss.elastic.co/t/logstash-consuming-cpu-usage-over-100/57084/12 "2017-07-06T04:44:08Z")

</div>