# Help needed with multiline codec, current pattern too slow

**URL:** <https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516>\
**Category:** Logstash\
**Created:** [October 3, 2017, 6:54am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516 "2017-10-03T06:54:42Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![nikhilsangvikar](https://avatars.discourse-cdn.com/v4/letter/n/bc8723/32.png) [@nikhilsangvikar](https://discuss.elastic.co/u/nikhilsangvikar)\
**Post date:** [October 3, 2017, 6:54am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516/1 "2017-10-03T06:54:42Z")

</div>

Hello, for these set of input lines:

## SAMPLE INPUT

```
INFO | jvm 1 | 2017/08/28 17:54:14 | 25306.601: Total time for which application threads were stopped: 0.0008632 seconds, Stopping threads took: 0.0000905 seconds
INFO | jvm 1 | 2017/08/28 17:54:17 | Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.141-b15 mixed mode):
INFO | jvm 1 | 2017/08/28 17:54:17 | 
INFO | jvm 1 | 2017/08/28 17:54:17 | "something-1" something
INFO | jvm 1 | 2017/08/28 17:54:17 | java.lang.Thread.State: TIMED_WAITING (on object monitor)
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | - locked something
INFO | jvm 1 | 2017/08/28 17:54:17 | 
INFO | jvm 1 | 2017/08/28 17:54:17 | Exception in thread "something-2" something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | Caused by: something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | ... 12 more
INFO | jvm 1 | 2017/08/28 17:54:17	| Caused by: something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17 | at something
INFO | jvm 1 | 2017/08/28 17:54:17	|	... 15 more
INFO | jvm 1 | 2017/08/28 17:54:17 | 
INFO | jvm 1 | 2017/06/20 19:58:39 | Heap
INFO | jvm 1 | 2017/06/20 19:58:39 | PSYoungGen total 2540032K, used 935016K [0x0000000759080000, 0x00000007fff80000, 0x0000000800000000)
INFO | jvm 1 | 2017/06/20 19:58:39 | eden space 2342400K, 36% used [0x0000000759080000,0x000000078d9adef8,0x00000007e8000000)
INFO | jvm 1 | 2017/06/20 19:58:39 | from space 197632K, 37% used [0x00000007f3e80000,0x00000007f866c470,0x00000007fff80000)
INFO | jvm 1 | 2017/06/20 19:58:39 | to space 195072K, 0% used [0x00000007e8000000,0x00000007e8000000,0x00000007f3e80000)
INFO | jvm 1 | 2017/06/20 19:58:39 | ParOldGen total 5470208K, used 1553638K [0x000000060b200000, 0x0000000759000000, 0x0000000759080000)
INFO | jvm 1 | 2017/06/20 19:58:39 | object space 5470208K, 28% used [0x000000060b200000,0x0000000669f399e8,0x0000000759000000)
INFO | jvm 1 | 2017/06/20 19:58:39 | PSPermGen total 230400K, used 230349K [0x00000005eb200000, 0x00000005f9300000, 0x000000060b200000)
INFO | jvm 1 | 2017/06/20 19:58:39 | object space 230400K, 99% used [0x00000005eb200000,0x00000005f92f3650,0x00000005f9300000)
INFO | jvm 1 | 2017/06/20 19:58:39 | 
INFO | jvm 1 | 2017/06/20 19:58:47 | 135695.454: Total time for which application threads were stopped: 0.0026100 seconds, Stopping threads took: 0.0001660 seconds
INFO | jvm 1 | 2017/06/20 19:58:52 | Returning empty Certificate from getAcceptedIssuers

```

From this, I need following blocks as output:

1. 25306.601: Total time .... (and similar single lines starting with a number)
2. Full thread dump Java....
3. the whole something-1 block
4. the whole something-2 block, including 'Caused by' blocks
5. Heap block
6. Returning empty Certificate..... (and similar single lines)

Currently, I'm using this in my input:

> input {  
> file {  
> type =\> "sometype"  
> path =\> "somepath"  
> start\_position =\> "beginning"  
> #ignore\_older =\> 0  
> sincedb\_path =\> "NUL"  
> #Forces to re-parse  
> codec =\> multiline {  
> pattern =\> "(?m)(%{DATA}|%{DATA}|%{DATA}| (( )|(\t))+)|(%{DATA}|%{DATA}|%{DATA}| Caused)"  
> what =\> "previous"  
> auto\_flush\_interval =\> 2  
> }  
> }  
> }

The output is then fed to elasticsearch.

**My issue is the processing rate is very slow. It is like 4-5 docs as output, per minute.**  
I usually get 2000-2500 docs/s as output, for some other type of log files.

I thought that maybe multiline codec is the one that is causing such drastic performance drop.

Please help.  
Thank you.

---

<div class="post-metadata">

**Author:** ![nikhilsangvikar](https://avatars.discourse-cdn.com/v4/letter/n/bc8723/32.png) [@nikhilsangvikar](https://discuss.elastic.co/u/nikhilsangvikar)\
**Post date:** [October 3, 2017, 6:55am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516/2 "2017-10-03T06:55:51Z")

</div>

Sorry due to max character limit, couldn't post my filter section. Here it is:  
filter {

```
if [type] == "sometype" {

	
	if "prio" in [message]
	{
		if ("multiline" in [tags]) {
			grok {
				match => {
					"message" => "(?m)%{DATA}\| %{YEAR:year}/%{MONTHNUM2:month}/%{MONTHDAY:day} %{TIME:time} \|%{DATA}nid=%{BASE16NUM:nid_hex}%{DATA}java.lang.Thread.State: %{DATA:thread_state}((\n)|(\r))%{DATA}"
				}
			}
		}
		else {
			grok {
				match => {
					"message" => "(?m)%{DATA}\| %{YEAR:year}/%{MONTHNUM2:month}/%{MONTHDAY:day} %{TIME:time} \|%{DATA}nid=%{BASE16NUM:nid_hex}%{DATA}"
				}
			}
		}
		ruby { 
			code => "event.set('nid_int', event.get('nid_hex').hex)" 
		}
		mutate {
			add_field => {
				"timestamp" => "%{year}-%{month}-%{day} %{time}"
			}
		}
		date {
			match => ["timestamp", "YYYY-MM-dd HH:mm:ss"]
			remove_field => ["timestamp","year","month","day","time"]
			#locale => "en"
			# timezone => "Asia/Kolkata"
			timezone => "Etc/GMT"			
		}
    }
	else if "Exception" in [message] {
		# EXCEPTION LINES
		# GET EXCEPTIONS
		if "Caused by" in [message] {
			# trace
			grok {
				# break_on_match => "false"
				match => { "message" => "(?m)%{DATA}\| %{YEAR:year}/%{MONTHNUM2:month}/%{MONTHDAY:day} %{TIME:time} \|%{DATA}\.(?<exception>[a-zA-Z]+)Exception:%{DATA}Caused by:%{DATA}\.(?<caused_by>[a-zA-Z]+)Exception%{GREEDYDATA}" }
				add_field => {
					"timestamp" => "%{year}-%{month}-%{day} %{time}"
				}
			}
		}
		else if "Exception" in [message] {
			grok {
				match => { "message" => "(?m)%{DATA}\| %{YEAR:year}/%{MONTHNUM2:month}/%{MONTHDAY:day} %{TIME:time} \|%{DATA}\.(?<exception>[a-zA-Z]+)Exception:%{GREEDYDATA}" }
				add_field => {
					"timestamp" => "%{year}-%{month}-%{day} %{time}"
				}
			}
		}
		date {
			match => ["timestamp", "YYYY-MM-dd HH:mm:ss"]
			remove_field => ["timestamp","year","month","day","time"]
			#locale => "en"
			timezone => "Etc/GMT"		
		}
	}
	else 
	{
		#non threaddump lines
		#drop {}
		grok {
			match => {
				"message" => "%{DATA:loglevel}%{SPACE}\|%{SPACE}%{DATA:field}%{SPACE}\| %{YEAR:year}/%{MONTHNUM2:month}/%{MONTHDAY:day} %{TIME:time} \| %{GREEDYDATA:details}"
			}
		}
		mutate {
			add_field => {
				"timestamp" => "%{year}-%{month}-%{day} %{time}"
			}
		}
		date {
			match => ["timestamp", "YYYY-MM-dd HH:mm:ss"]
			remove_field => ["timestamp","year","month","day","time","message"]
			#locale => "en"
			# timezone => "Asia/Kolkata"
			timezone => "Etc/GMT"			
		}
		if ("Total time for which application threads were stopped" in [details]) {
			#drop {}
			grok {
					match => { "details" => "%{NUMBER:collection_time:float}: Total time for which application threads were stopped: %{NUMBER:app_thread_stopped:float} seconds, Stopping threads took: %{NUMBER:stop_threads:float} seconds"
				}
			}
		}
		else if("PSYoungGen" in [details] and "ParOldGen" not in [details])
		{
			# drop {}
			grok { #-- [PSYoungGen: 2538481K->2538481K(2538496K)] 7869259K->8009199K(8009216K), 0.8418280 secs] [Times: user=1.67 sys=0.47, real=0.84 secs]
					match => { "details" => "%{DATA}\[PSYoungGen: %{NUMBER:young_gen_before:int}K->%{NUMBER:young_gen_after:int}K\(%{NUMBER:young_gen_total:int}K\)\] %{NUMBER:overall_before:int}K->%{NUMBER:overall_after:int}K\(%{NUMBER:overall_total:int}K\), %{NUMBER:gc_time:float} secs\] \[Times: user=%{NUMBER:user_time:float} sys=%{NUMBER:sys_time:float}, real=%{NUMBER:real_time:float} secs\]"
				}
			}
			mutate {
				add_field => {
					"linetype" => "gc"
				}
			}
		}
		else if ("ParOldGen" in [details]){
			# drop {}
			grok { # [PSYoungGen: 83718K->0K(2549248K)] [ParOldGen: 5400973K->1594715K(5470208K)] 5484691K->1594715K(8019456K) [PSPermGen: 230277K->230277K(230400K)], 2.4420490 secs] [Times: user=7.85 sys=0.00, real=2.44 secs] 
					match => { "details" => "%{SPACE}\[PSYoungGen: %{NUMBER:young_gen_before:int}K->%{NUMBER:young_gen_after:int}K\(%{NUMBER:young_gen_total:int}K\)\] \[ParOldGen: %{NUMBER:old_gen_before:int}K->%{NUMBER:old_gen_after:int}K\(%{NUMBER:old_gen_total:int}K\)\] %{NUMBER:overall_before:int}K->%{NUMBER:overall_after:int}K\(%{NUMBER:overall_total:int}K\) \[PSPermGen: %{NUMBER:perm_gen_before:int}K->%{NUMBER:perm_gen_after:int}K\(%{NUMBER:perm_gen_total:int}K\)\], %{NUMBER:gc_time:float} secs\] \[Times: user=%{NUMBER:user_time:float} sys=%{NUMBER:sys_time:float}, real=%{NUMBER:real_time:float} secs\]"
				}
			}
			mutate {
				add_field => {
					"linetype" => "fullgc"
				}
			}
		}
		else if ("Cannot allocate memory" in [details]) {
			mutate {
				add_field => {
					"linetype" => "outofmemory"
				}
			}
		}
		else {
			drop {}
		}
	}
}	

```

}

---

<div class="post-metadata">

**Author:** ![nikhilsangvikar](https://avatars.discourse-cdn.com/v4/letter/n/bc8723/32.png) [@nikhilsangvikar](https://discuss.elastic.co/u/nikhilsangvikar)\
**Post date:** [October 10, 2017, 4:12am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516/3 "2017-10-10T04:12:53Z")

</div>

bump?

---

<div class="post-metadata">

**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\
**Post date:** [October 10, 2017, 5:17am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516/4 "2017-10-10T05:17:56Z")

</div>

You are using a lot of `DATA` patterns, which can be expensive to process. Try replacing these with as specific patterns as possible and see how that affects throughput.

---

<div class="post-metadata">

**Author:** ![nikhilsangvikar](https://avatars.discourse-cdn.com/v4/letter/n/bc8723/32.png) [@nikhilsangvikar](https://discuss.elastic.co/u/nikhilsangvikar)\
**Post date:** [October 10, 2017, 6:08am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516/5 "2017-10-10T06:08:24Z")

</div>

Thanks, will try it and let you know.

---

<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:** [November 7, 2017, 6:08am UTC](https://discuss.elastic.co/t/help-needed-with-multiline-codec-current-pattern-too-slow/102516/6 "2017-11-07T06:08:46Z")

</div>

Closed on November 7, 2017, 6:08am UTC

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