Grok filter behaviour different for some messages

Elastic Stack Logstash
1

Hi All,

I am currently trying to setup some data collections for our app using the full elk stack (Beats - Logstash - ElasticSearch-Kibana). So far everything is working as it should but I have a requirement to capture statistics on the exceptions thrown by the applications (e.g. java.lang.IllegalArgumentException)

I am not really interested in the stack trace itself so I went ahead and added a separate grok filter just for the exception.

Example of Message:

2016-11-15 05:19:28,801 ERROR [App-Initialisation-Thread] appengine.java:520 Failed to initialize external authenticator myapp Support Access || appuser@vm23-13:/mnt/data/install/assembly app-1.4.12@cad85b224cce11eb5defa126030f21fa867b0dad
java.lang.IllegalArgumentException: Could not check if provided root is a directory
	at com.myapp.io.AbstractRootPrefixedFileSystem.checkAndGetRoot(AbstractRootPrefixedFileSystem.java:67)
	at com.myapp.io.AbstractRootPrefixedFileSystem.<init>(AbstractRootPrefixedFileSystem.java:30)
	at com.myapp.io.s3.S3FileSystem.<init>(S3FileSystem.java:32)
	at com.myapp.io.s3.S3FileSystemDriver.loadFileSystem(S3FileSystemDriver.java:60)
	at com.myapp.io.FileSystems.getFileSystem(FileSystems.java:55)
	at com.myapp.authentication.ldap.S3LdapConfigProvider.initializeCloudFS(S3LdapConfigProvider.java:77)
	at com.myapp.authentication.ldap.S3LdapConfigProvider.loadS3Config(S3LdapConfigProvider.java:51)
	at com.myapp.authentication.ldap.S3LdapConfigProvider.getLdapConfig(S3LdapConfigProvider.java:42)
	at com.myapp.authentication.ldap.DelegatingLdapConfigProvider.getLdapConfig(DelegatingLdapConfigProvider.java:45)
	at com.myapp.authentication.ldap.LdapExternalAuthenticatorFactory.create(LdapExternalAuthenticatorFactory.java:28)
	at com.myapp.authentication.ldap.LdapExternalAuthenticatorFactory.create(LdapExternalAuthenticatorFactory.java:10)
	at com.myapp.frob.appengine.getExternalAuthenticators(appengine.java:516)
	at com.myapp.frob.appengine.startUp(appengine.java:871)
	at com.myapp.frob.appengine.startUp(appengine.java:754)
	at com.myapp.jsp.KewServeInitContextListener$1.run(QServerInitContextListener.java:104)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.nio.file.NoSuchFileException: fh-ldap-config/
	at com.upplication.s3fs.util.S3Utils.getS3ObjectSummary(S3Utils.java:55)
	at com.upplication.s3fs.util.S3Utils.getS3FileAttributes(S3Utils.java:64)
	at com.upplication.s3fs.S3FileSystemProvider.readAttributes(S3FileSystemProvider.java:463)
	at com.myapp.io.AbstractRootPrefixedFileSystem.checkAndGetRoot(AbstractRootPrefixedFileSystem.java:61)

Example of grok statement:
grok {
patterns_dir => ["./patterns"]
match => ["message", "%{GREEDYDATA}\n%{JAVAFILE:exception}"]
}

Testing on the grok debugger shows correct results:

{
  "GREEDYDATA": [
    [
      "2016-11-15 05:19:28,801 ERROR [App-Initialisation-Thread] appengine.java:520 Failed to initialize external authenticator myapp Support Access || appuser@vm23-13:/mnt/data/install/assembly app-1.4.12@cad85b224cce11eb5defa126030f21fa867b0dad"
    ]
  ],
  "exception": [
    [
      "java.lang.IllegalArgumentException"
    ]
  ]
}

Problem

When I add the configuration to logstash it captures the Caused string instead of the exception name, even though the "Caused" string is after another new line character. However it works perfectly for other exception messages such as :

016-11-15 06:17:49,691 WARN  [SCReplicationWorkerThread-2] ClientJob.java:207 50345 Error communicating to server `199.181.131.249':`80'. Waiting `10' seconds before retrying... If you see this message rarely, the sc will have recovered gracefully. || appuser@vm55-12:/mnt/deployment/install/app app-3.1.23@cad85b224cce11eb5defa126030f21fa867b0dad
java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:170)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.net.SocketInputStream.read(SocketInputStream.java:223)
	at java.io.DataInputStream.readBoolean(DataInputStream.java:242)
	at com.myapp.replication.client.ClientJob.passCheckRevision(ClientJob.java:279)
	at com.myapp.replication.client.ClientJob.execute(ClientJob.java:167)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:534)

Any advice would be appreciated.

Thanks

2

So it is possible that if there are multiple values the last value is written to the field. I am currently trying to work around the issue by creating a custom regex pattern which still captures the "Caused by" and then re-running it through a mutate->replace

I will update on progress

3

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