[CLOSED / USER ERROR] Filebeat -> Logstash multi-line

Elastic Stack Logstash
1

Hi all,

I've searched high and low to get an answer to this, but no success so far. Hope someone can help.

I'm trying to get multi-line processing of Java Exceptions to work correctly. My Filebeat configuration contains the following (with the goal of treating lines that begin with a date as the start of a multi-line message):

- input_type: log
  paths:
    - C:\ProgramData\Tableau\Tableau Server\data\tabsvc\logs\vizqlserver\vizql*.log*
  document_type: vizql
  multiline:
    pattern: "^[[:digit:]]{4}-[[:digit:]]{2}-[[:digit:]]{2}"
    negate: true
    match: after

I have tested this using the Go Playground (https://play.golang.org/p/uAd5XHxscu), and as far as I can tell, it appears the configuration will work correctly (i.e. it will pull in an entire stacktrace as a single message). However, when I look in Kibana, it appears that only part of the message is brought in as part of the multi-line message.

The following is shown in the message in Kibana:
= = = Begin = = =
2017-02-20 13:59:47.356 -0800 (Default,local\aaaadmin,29D35C6456BD477798E3D701BCA3EEBB-0:1,WKtm0wrmjx8AACx41c8AAAGl) catalina-exec-17 : ERROR wgsessionId=B2aYkfzAbnSF5DPVBJ553sO5NUrwkPHD com.tbsoftware.controller.vizql.ExceptionController - WrappedTbException caught for vizql session: 29D35C6456BD477798E3D701BCA3EEBB-0:1
com.tbsoftware.model.vizql.WrappedTbException: Failed to copy file 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp' to 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\TbTemp\0t8veen131kn1r145ccwa1x3c973.tmp':
Error copying file 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp' to 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\TbTemp\0t8veen131kn1r145ccwa1x3c973.tmp' (Cannot open C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp for input)

The system cannot find the file specified.
= = = End = = =

However, the actual stacktrace is more like the following:
= = = Begin = = =
2017-02-20 13:59:47.356 -0800 (Default,local\aaaadmin,29D35C6456BD477798E3D701BCA3EEBB-0:1,WKtm0wrmjx8AACx41c8AAAGl) catalina-exec-17 : ERROR wgsessionId=B2aYkfzAbnSF5DPVBJ553sO5NUrwkPHD com.tbsoftware.controller.vizql.ExceptionController - WrappedTbException caught for vizql session: 29D35C6456BD477798E3D701BCA3EEBB-0:1
com.tbsoftware.model.vizql.WrappedTbException: Failed to copy file 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp' to 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\TbTemp\0t8veen131kn1r145ccwa1x3c973.tmp':
Error copying file 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp' to 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\TbTemp\0t8veen131kn1r145ccwa1x3c973.tmp' (Cannot open C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp for input)

The system cannot find the file specified.

at com.tbsoftware.model.vizql.util.ErrorMapper.runAndCatchErrors(ErrorMapper.java:126)
at com.tbsoftware.model.vizql.util.WithSessionAspect.acquireAndReleaseSession(WithSessionAspect.java:129)
{...simplified...}
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

Caused by: com.tbsoftware.nativeapi.dll.TbException: Failed to copy file 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp' to 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\TbTemp\0t8veen131kn1r145ccwa1x3c973.tmp':
Error copying file 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp' to 'C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\TbTemp\0t8veen131kn1r145ccwa1x3c973.tmp' (Cannot open C:\ProgramData\Tb\Tb Server\data\tabsvc\temp\repoItem3566480437030000907.tmp for input)

The system cannot find the file specified.

at com.tbsoftware.nativeapi.dll.TbException.getTbException(TbException.java:39)
at com.tbsoftware.nativeapi.dll.NativeApiJNI.VQLSessionDelegate_GetOrUpdateCachedBootstrap(Native Method)
{...simplified...}
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at com.tbsoftware.model.vizql.util.ErrorMapper.runAndCatchErrors(ErrorMapper.java:64)
... 68 more

= = = End = = =

Any thoughts why Logstash/ES/Kibana seems to not be showing the full message?

Thanks,
Greg

2

Sorry, I see the spaces/tabs at the beginning of some lines have caused code boxes to be created. Please ignore that.

3

FYI, using the filebeat -d "publish" option I was able to determine that the full stacktrace is, indeed, being published by Filebeat. But somehow it's not all ending up in ES.

4

Turns out this was all a misunderstanding on my part. Seems both Filebeat and Logstash were publishing the full stacktrace, and it was being successfully loaded into ES. What happened is that there were two messages for the same event in the log -- with the exact same timestamp. One was a short version of the other. I was confused because I was seeing the long version in the logs and the short version in ES/Kibana. I later found both versions in the logs and ES/Kibana. Problem solved.

Sorry for wasting everyone's time.

5

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