Apply multiline codec and filter

anudeepmk · December 18, 2017, 6:11am

I have the log files generated from one of our hybris as below,

INFO | jvm 1 | main | 2017/12/18 04:13:28.985 | at org.zkoss.zk.ui.impl.EventProcessingThreadImpl.run(EventProcessingThreadImpl.java:446) [zk-3.6.4-hybris-patched.jar:3.6.4] INFO | jvm 1 | main | 2017/12/18 04:13:28.985 | Caused by: de.hybris.platform.media.exceptions.MediaNotFoundException: Media not found (requested media location: hc9/h2d/8796270886942/AdvancedSearch_Unit_CockpitUser.xml) INFO | jvm 1 | main | 2017/12/18 04:13:28.985 | at de.hybris.platform.azure.media.storage.WindowsAzureBlobStorageStrategy.getAsStream(WindowsAzureBlobStorageStrategy.java:195) ~[azurecloudserver.jar:?]

and some times as below

INFO | jvm 1 | main | 2017/12/18 03:24:39.826 | WARN [hybrisHTTP2] [ip addr] [StructureLoader] 'medias' is already used in the editor. Removing AttributeChipNode! (see knowledgebase (dev.hybris.de) for further information) INFO | jvm 1 | main | 2017/12/18 03:24:39.826 | WARN [hybrisHTTP2] [ip addr] [StructureLoader] 'code' is already used in the editor. Removing AttributeChipNode! (see knowledgebase (dev.hybris.de) for further information) INFO | jvm 1 | main | 2017/12/18 03:24:39.826 | WARN [hybrisHTTP2] [ip addr] [StructureLoader] * Type User (User): INFO | jvm 1 | main | 2017/12/18 03:24:39.826 | WARN [hybrisHTTP2] [ip addr] [StructureLoader] 'name' is already used in the editor. Removing AttributeChipNode! (see knowledgebase (dev.hybris.de) for further information)

If exceptions occur like(Caused by...), I need to get those messages by the logstash, How do I achieve this?

I made my multiline codec as the lines which dont begin. with (INFO) to match to previous line and my configuration looks as below

`
input {

  file {
	path => ["/hybris/log/wrapper-*.log"]
	start_position => "beginning"
	sincedb_path => "/dev/null"
	codec => multiline {
		pattern => "^%{LOGLEVEL}"
		negate => true
		what => "previous"
	}
}

 }
   filter {

    mutate {
      gsub => [ "message", "\e\[(0;)?([0-9]{1,2}(;[0-9]{1,2})?)?[m|K]", "" ]
     }

mutate {
	gsub => ["message", "\|", " "]
}

grok {
	match => { "message" => "(?m)%{GREEDYDATA:msg} %{YEAR:year}/%{MONTHNUM:month}/%{MONTHDAY:day}%{SPACE}%{TIME:time}   %{LOGLEVEL:level}  %{NOTSPACE:hybristype} (\[%{IPV4:ip}\])?%{GREEDYDATA:text}"}
}

mutate {
	add_field => { "logtimestamp" => "%{year}-%{month}-%{day} %{time}" }
	remove_field => ["message", "@version", "hybristype", "msg", "year", "month", "day", "time", 
          "path"]
}

if "_grokparsefailure" in [tags] {
   drop { }
     }}

 output {
elasticsearch {
	hosts => "elasticip:9200"
	index => "prototype_hybris"
}
   stdout { codec => rubydebug }
}

As far as I think, my configuration does not catch the exceptions. How do I achieve this please suggest?

magnusbaeck · December 18, 2017, 6:21am

That configuration looks okay. What happens when you feed it a multiline message?

anudeepmk · December 18, 2017, 7:13am

It works fine for these below logs

INFO | jvm 1 | main | 2017/12/11 20:37:36.492 | INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
INFO | jvm 1 | main | 2017/12/11 20:37:36.693 | INFO [localhost-startStop-1] [TenantAwareEhCacheManagerFactoryBean] Initializing EhCache CacheManager 'warehousingwebservicesmaster'
INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | ERROR [hybrisHTTP10] [170.251.41.109] [DefaultDeliveryService] Failed to get delivery cost for order: 00025000

But when the below lines come, it hangs or stops processing

INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | de.hybris.platform.jalo.order.delivery.JaloDeliveryModeException: getCost(): delivery address was NULL in order 00025000(8796912255019)
INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | at de.hybris.platform.deliveryzone.jalo.ZoneDeliveryMode.getCost(ZoneDeliveryMode.java:258) ~[deliveryzoneserver.jar:?]
INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | at de.hybris.platform.jalo.order.delivery.DeliveryMode.getCost(DeliveryMode.java:203) ~[coreserver.jar:?]
INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | at de.hybris.platform.commerceservices.delivery.impl.DefaultDeliveryService.getDeliveryCostForDeliveryModeAndAbstractOrder(DefaultDeliveryService.java:234) [commerceservicesserver.jar:?]
INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | at de.hybris.platform.commercefacades.order.impl.DefaultCheckoutFacade.convert(DefaultCheckoutFacade.java:374) [commercefacadesserver.jar:?]
INFO | jvm 1 | main | 2017/12/18 04:33:32.257 | at de.hybris.platform.commercefacades.order.impl.DefaultCheckoutFacade.getDeliveryMode(DefaultCheckoutFacade.java:331) [commercefacadesserver.jar:?]

I also tried to change my grok to

grok {

	match => { "message" => "(?m)%{GREEDYDATA:msg} %{YEAR:year}/%{MONTHNUM:month}/%
 {MONTHDAY:day}%{SPACE}%{TIME:time}   %{LOGLEVEL:level}%{GREEDYDATA:text}"}
}

I am using my multiline filter on the basis of line beginning with "INFO" but in my case for every log line it is adding
"INFO | jvm 1 | main | 2017/12/11 20:37:36.693 |"

Please suggest?

magnusbaeck · December 18, 2017, 9:26am

Oh. No, using the multiline codec to parse this stupid log format is not going to be fun. Is there any chance you can modify how the application logs? In not I see two unappealing options:

Modify the codec configuration to join with the previous line if the message part begins with "at ".
Drop the multiline codec and use the (deprecated) multiline filter instead and use it to remove the timestamp and loglevel prefix if the message part begins with "at ".

anudeepmk · December 18, 2017, 11:18am

No but the time stamp is added to each line , I cant know if a line begins with 'at' since "INFO | jvm 1 | main | 2017/12/18 04:33:32.257" would be already added in front of each line.

magnusbaeck · December 18, 2017, 11:39am

You don't need to check if the line begins with "at", you can check if the message part begins with "at". You already have a grok expression for the loglevel and timestamp stuff.

anudeepmk · December 18, 2017, 11:52am

@magnusbaeck, could you please show me the configuration , how do I achieve that?I am unable to figure out

magnusbaeck · December 18, 2017, 2:01pm

Try changing your codec configuration to something like this:

pattern => "^%{LOGLEVEL}\s+\| %{WORD} %{NUMBER} \| %{WORD} \| %{YEAR:year}/%{MONTHNUM:month}/%{MONTHDAY:day} %{TIME:time}"\| at "
what => "previous"
negate => false

anudeepmk · December 19, 2017, 8:37am

Thank you @magnusbaeck, I actually happened to get the logging format changed as below

2017-12-19 11:42:52,797 [INFO |||com.omsencore.actions.order.GeocodeShippingAddressAction|] Fail to obtain geocode from order.deliveryAddress, error message: null
2017-12-19 11:43:02,884 [INFO |||com.omsencore.actions.order.StartConsignmentSubProcessAction|] Process:.-order-process-00029005-1513669282233 in step class com.omsencore.actions.order.StartConsignmentSubProcessAction
2017-12-19 11:46:57,166 [WARN |||de.hybris.platform.acceleratorservices.process.strategies.impl.AbstractProcessContextStrategy|] Failed to lookup BaseSite for BusinessProcess [customerRegistrationEmailProcess-jijikoko@oko.com-1513669606993]. Unable to setup site in session.

it doesnt add timestamp to each line, unless it is a new line

system · January 16, 2018, 8:37am

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