Dissect combined with multiline pattern gives errors

kainazzzo · July 3, 2020, 4:43am

I have log files being picked up and dissected fine when they are single line. I even have a multi line pattern ensuring that the message attribute contains all the lines I want.

What I can't seem to figure out is how to use the dissect processor when the event is a multi line event. I keep getting these log.flags: multiline, dissect_parsing_error

Here's a sample of my log format:

    2020-05-12 15:31:52,853 [main] INFO  com.organization.className - Rest of message
    2020-05-12 15:34:52,853 [main] INFO  com.organization.className - Rest of message 2
    2020-05-12 15:35:52,853 [main] INFO  com.organization.className - Rest of message 3
    2020-05-12 15:36:52,853 [main] INFO  com.organization.className - Rest of message 4
    but sometimes it goes on for multiple lines
    like this
      sometimes there are spaces and then stack traces
      I did not mean to rhyme
    2020-05-12 15:39:52,853 [main] INFO  com.organization.className - Rest of message

Here is the relevant part of my filebeat.yml:

    filebeat.inputs:
      - type: log
        enabled: true
        paths:
          - /opt/logs/*.log
    
        processors:
          - dissect:
              tokenizer: "%{logtime} %{+logtime} [%{src}] %{loglevel}  %{classname} - %{msg}"
              field: "message"
              target_prefix: ""
        multiline.pattern: '^[0-9]{4}-[0-9]{2}-[0-9]{2}'
        multiline.negate: true
        multiline.match: after

I am outputting to logstash, and I have attempted to dissect it on that side with the same pattern, but I get the same output.

shaunak · July 6, 2020, 3:18pm

Hi @kainazzzo, welcome to the Elastic community forums!

Hmm, I just tested your configuration and sample input with Filebeat built off the master branch and it works as expected.

My filebeat configuration file, filebeat.test.yml:

filebeat.inputs:
  - type: stdin
    processors:
      - dissect:
          tokenizer: "%{logtime} %{+logtime} [%{src}] %{loglevel}  %{classname} - %{msg}"
          field: message
          target_prefix: ""
    multiline:
      pattern: '^[0-9]{4}-[0-9]{2}-[0-9]{2}'
      negate: true
      match: after
      
output.console:
  enabled: true

Running Filebeat:

$ /filebeat -c filebeat.test.yml
2020-05-12 15:31:52,853 [main] INFO  com.organization.className - Rest of message
2020-05-12 15:34:52,853 [main] INFO  com.organization.className - Rest of message 2
2020-05-12 15:35:52,853 [main] INFO  com.organization.className - Rest of message 3
2020-05-12 15:36:52,853 [main] INFO  com.organization.className - Rest of message 4
but sometimes it goes on for multiple lines
like this
  sometimes there are spaces and then stack traces
  I did not mean to rhyme
2020-05-12 15:39:52,853 [main] INFO  com.organization.className - Rest of message
{"@timestamp":"2020-07-06T15:15:25.940Z","@metadata":{"beat":"filebeat","type":"_doc","version":"8.0.0"},"logtime":"2020-05-12 15:31:52,853","agent":{"type":"filebeat","version":"8.0.0","ephemeral_id":"3c793acb-c2e4-439b-a715-c5c73187830f","id":"e3c91a8c-d8e3-4ac2-a32b-4acbd7caba77","name":"Shaunaks-MacBook-Pro-Work.local"},"host":{"name":"Shaunaks-MacBook-Pro-Work.local"},"input":{"type":"stdin"},"classname":"com.organization.className","loglevel":"INFO","msg":"Rest of message","src":"main","ecs":{"version":"1.5.0"},"log":{"file":{"path":""},"offset":0},"message":"2020-05-12 15:31:52,853 [main] INFO  com.organization.className - Rest of message"}
{"@timestamp":"2020-07-06T15:15:25.940Z","@metadata":{"beat":"filebeat","type":"_doc","version":"8.0.0"},"input":{"type":"stdin"},"src":"main","loglevel":"INFO","agent":{"ephemeral_id":"3c793acb-c2e4-439b-a715-c5c73187830f","id":"e3c91a8c-d8e3-4ac2-a32b-4acbd7caba77","name":"Shaunaks-MacBook-Pro-Work.local","type":"filebeat","version":"8.0.0"},"ecs":{"version":"1.5.0"},"host":{"name":"Shaunaks-MacBook-Pro-Work.local"},"log":{"offset":0,"file":{"path":""}},"message":"2020-05-12 15:34:52,853 [main] INFO  com.organization.className - Rest of message 2","logtime":"2020-05-12 15:34:52,853","classname":"com.organization.className","msg":"Rest of message 2"}
{"@timestamp":"2020-07-06T15:15:25.940Z","@metadata":{"beat":"filebeat","type":"_doc","version":"8.0.0"},"ecs":{"version":"1.5.0"},"host":{"name":"Shaunaks-MacBook-Pro-Work.local"},"log":{"offset":0,"file":{"path":""}},"classname":"com.organization.className","logtime":"2020-05-12 15:35:52,853","loglevel":"INFO","msg":"Rest of message 3","agent":{"type":"filebeat","version":"8.0.0","ephemeral_id":"3c793acb-c2e4-439b-a715-c5c73187830f","id":"e3c91a8c-d8e3-4ac2-a32b-4acbd7caba77","name":"Shaunaks-MacBook-Pro-Work.local"},"message":"2020-05-12 15:35:52,853 [main] INFO  com.organization.className - Rest of message 3","input":{"type":"stdin"},"src":"main"}
{"@timestamp":"2020-07-06T15:15:25.940Z","@metadata":{"beat":"filebeat","type":"_doc","version":"8.0.0"},"classname":"com.organization.className","msg":"Rest of message 4\nbut sometimes it goes on for multiple lines\nlike this\n  sometimes there are spaces and then stack traces\n  I did not mean to rhyme","logtime":"2020-05-12 15:36:52,853","loglevel":"INFO","ecs":{"version":"1.5.0"},"log":{"flags":["multiline"],"offset":0,"file":{"path":""}},"input":{"type":"stdin"},"src":"main","host":{"name":"Shaunaks-MacBook-Pro-Work.local"},"agent":{"type":"filebeat","version":"8.0.0","ephemeral_id":"3c793acb-c2e4-439b-a715-c5c73187830f","id":"e3c91a8c-d8e3-4ac2-a32b-4acbd7caba77","name":"Shaunaks-MacBook-Pro-Work.local"},"message":"2020-05-12 15:36:52,853 [main] INFO  com.organization.className - Rest of message 4\nbut sometimes it goes on for multiple lines\nlike this\n  sometimes there are spaces and then stack traces\n  I did not mean to rhyme"}
{"@timestamp":"2020-07-06T15:15:26.614Z","@metadata":{"beat":"filebeat","type":"_doc","version":"8.0.0"},"input":{"type":"stdin"},"ecs":{"version":"1.5.0"},"agent":{"type":"filebeat","version":"8.0.0","ephemeral_id":"3c793acb-c2e4-439b-a715-c5c73187830f","id":"e3c91a8c-d8e3-4ac2-a32b-4acbd7caba77","name":"Shaunaks-MacBook-Pro-Work.local"},"message":"2020-05-12 15:39:52,853 [main] INFO  com.organization.className - Rest of message","classname":"com.organization.className","msg":"Rest of message","logtime":"2020-05-12 15:39:52,853","src":"main","loglevel":"INFO","host":{"name":"Shaunaks-MacBook-Pro-Work.local"},"log":{"offset":0,"file":{"path":""}}}

What version of Filebeat are you using? Once you tell me that I can try to reproduce the issue with that version.

Thanks!

Shaunak

kainazzzo · July 6, 2020, 9:07pm

@shaunak thank you for your reply. I'm using filebeat 7.8.0 from the docker image elastic provides.

I created this example to illustrate the problem I'm having, but I didn't think to try it myself from the example. I now think this might be a line ending problem... This example works for me, AND if I copy and paste a real logfile into a test log, it works.

I did confirm that the issue persists when I pipe a real log file into this simplified filebeat configuration.

I will continue to research given this new information you helped uncover. Thanks!

kainazzzo · July 7, 2020, 8:07pm

So, I believe filebeat w/ dissect requires carriage return + line feed for new lines (0x0D)(0x0A), and it's puking if the file only has line feeds (0x0A). If you can somehow remove the (0x0D) characters and retry this, it should fail @shaunak

Edit: I tried this and I was wrong... still trying to figure out why my logs fail to tokenize like this.

I think I said this backwards. The test should have been to add carriage returns... been looking at this too long.

kainazzzo · July 8, 2020, 7:29pm

Well I took my file, changed all the line endings from LF to CR LF (unix to windows... I'm aware this was a silly thing to think broken), and it still doesn't process properly. It's not a line ending issue. Still investigating.

kainazzzo · July 8, 2020, 7:40pm

I finally figured it out by using the -e -d "*" flags on filebeat and observing the errors in the stderr output.

Log4j is left justifying the log level (INFO vs. ERROR). This results in two spaces after INFO, but one after ERROR. I had two spaces as my dissect tokenizer delimiter.

Moving to one space causes it to parse, but then there's a leading space in the INFO messages' class names. Maybe I can trim this with another processor.

Thanks for replying to tell me it worked for you @shaunak ... that ultimately pointed me in the right direction.

system · August 5, 2020, 9:40pm

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

Topic		Replies	Views
Filebeat dissect line break Beats filebeat	7	1527	June 3, 2021
About FileBeat Dissect processor Beats filebeat	2	870	October 28, 2022
Parsing logs filebeat Beats filebeat	4	792	June 2, 2021
Filebeat multiline works as single liners Beats filebeat	2	582	March 4, 2019
Multiline Pattern not Working Beats filebeat	1	517	October 7, 2019

Dissect combined with multiline pattern gives errors

Related topics