Parsing multiline logs


(F) #1

I am attempting to index a log file that consist of multilines and it appears one set of multilines is parsing correctly but the other isn't. Its being parsed as a separate log entry.
Sample Log file:

2017-12-12 02:44:35,456 [11-1234567890] [] []  DEBUG RequestLogger Response: SwitchingProtocols 
2017-12-12 02:44:35,456 [(null)] [1234567] [(null)] (null) DEBUG AppName a122d567-1234-5678-9012-aabbcceedd - Command: BeginTransaction - Response: AQAAAasdfasdfasdfasdfasdfasdfasdfasdfsadfasdfEAAABUUzAxLVFBSFlTMDEzAGF0HAAAAFQAUwAwADEALQBRAEEASABZAFMAMAAxADMAAAABAAAAAAAVFBSFlTMDEzLmhlZGdlc2VydnRlc3QuY29tLwAn
2017-12-12 02:44:35,519 [2-12345] [6666666] [] Jump_To_TE DEBUG RequestLogger Request: PUT https://aa02-abcde111.somename.com/api/dummyHis
{"SomeNameName": "Default Primary Some Name", "asdfasdfasdf": "ASDF", "AasdfasdfasdfName": "ASD/ASD 04/21/19", "LISTFactor": 2, "Date": "22200e-00-07T00:00:00", "DICE": 1.345345345}
2017-12-12 02:44:35,581 [3-12313131313131313131] [1231232131] [100] NANME_BLUE_DZ DEBUG RequestLogger Response: OK 
2017-12-12 02:44:35,597 [88-34534534534534534] [1313131331] [] Single_HARD_D_2 INFO  APPNAME HUH with dummy id : 2344 inserted with status : Success ( Message: ) for WWClientId: 20
2017-12-12 02:44:37,586 [0-asdfasdfasdfasdfasdfsa] [] []  DEBUG RequestLogger Response: SwitchingProtocols 
2017-12-12 02:44:37,586 [(null)] [345345345] [(null)] (null) DEBUG Jumpk 124123123-3434-3434-3434-3434343434 - Command: BeginDUMMY - Response: ASDFASDFASDFSADFSADFSADFSADFSADFSADFSADFASDFSAFSADFASDFSADFSADFSADFASFASDFASDFSADFSADFSADFASDFASDFSADFASDFSADFASDFSADFSADFSADFSDFAGSADFASDFSADFASDFSADFASDFASDFASDFASDFASDFASDFTEyM2Y2ZTZiNQAtNDgNAAAAZM1kzSEAAABUUzAxLVFBSFlTMDEzAGF0HAAAAFQAUwAwADEALQBRAEEASABZAFMAMAAxADMAAAABAAAAAAAAACYAAAB0aXA6Ly9UUzAxLVFBSFlTMDEzLmhlZGdlc2VydnRlc3QuY29t
2017-12-12 02:44:37,649 [55-123412341234123412341] [-12312312312] [] JUMP_MAN_AA_BCD_YOOOO_AWESOME_CLEAR_YUP_ASDFASDFA3442 DEBUG RequestLogger Request: POST https://aaa-asfasdf.asfdasdf.com/api/YUP/Batch
[{"RATE": 1.123123123, "JUMPMANType": "HAHAHA", "DUMMYNumber": 1234, "actionNumber": null, "Date": "20023-04-30T00:00:00", "Security": "ABR/LOG/LOG 2003123-04-70 201238-024-aed29", "Name": null, "Date": null, "Name": "located", "Price": null, "unt": null, "Code": false, "ithotor": -000.000000, "Locarate": 1.0klj000000, "Quaity": -10-09-0, "Date": "20-0908-04-30T00:00:00", "TraTreatment": "", "SeeNumber": 15009-0901002, "Date": "20-090908-04-24T00:00:00", "rate": null, "0989ce": 0.8908098800000, "Date": "20-089008-04-24T00:00:00", "ocessed": true, "ercentage": null, "onCode": "or", "yCode": "SD", "Amount": null, "Active": true, "fier": 8908, "rest": false, "Name": "r 2", "TrFes": [], "PorName": "rt", "Amount": null, "Type": ""}]
2017-12-12 02:44:37,774 [33-2234234234234324] [-3123123123] [] JUMP_MAN_TT_TDE_CRIP_in_Blood_AAB_AB12313 INFO  ANAME raid with raid id : 1233 inserted with status : Success ( Message: ) for HsClientId: 20
2017-12-12 02:44:37,774 [123-123123123123123123] [-123123123] [22] HI_ME_UD_TDE_GANG_in_BGANGase_AAC_S123123862 DEBUG RequestLogger Response: OK 

filebeat.yml:

filebeat:

  prospectors:
    -
      paths:
        - /home/name/name/*.log
      input_type: log
      ignore_older: 24h
      multiline.pattern: '^[[:punct:]]'
      multiline.negate: false
      multiline.match: after
      fields:
        client: "name"
        tags: "Q"
        type: "api"
      fields_under_root: true

   registry_file: /var/lib/filebeat/registry
output:
    logstash:
      hosts: ["192.198.222.118:5044"]


logging:

  files:

    rotateeverybytes: 10485760 # = 10MB
  level: debug

grok pattern:

filter {
if [type] == "api" {
grok {
  match => {"message" => "%{TIMESTAMP_ISO8601:Timestamp} \[%{DATA:CID}] \[%{DATA:TID}] \[%{DATA:HClient}]\s(%{DATA:TName}) %{WORD:LogLevel} %{GREEDYDATA:Message}\s\[%{DATA:questBody}]"}
  match => {"message" => "%{TIMESTAMP_ISO8601:Timestamp} \[%{DATA:CID}] \[%{DATA:TID}] \[%{DATA:HClient}]\s(%{DATA:TName}) %{WORD:LogLevel} %{GREEDYDATA:Message}"}
  match => {"message" => "%{TIMESTAMP_ISO8601:timestamp} \[%{DATA:CID}] \[%{DATA:TID}] \[%{DATA:HClient}]\s %{WORD:LogLevel} %{GREEDYDATA:Message}"}
  }
 }
}

The multiline that beings with "{"SomeNameName":" gets parsed correctly but the second multiline that begins with "[RATE:" gets parsed into a separate log entry and not getting the proper file name of questBody from the grok pattern. I've tried several different multiline.pattern options as well as changing the negate to true.


(Noémi Ványi) #2

You can set you pattern differently to match the date at the beginning of your log lines.

multiline.pattern: '^[0-9]{4}-[0-9]{2}-[0-9]{2}'
multiline.negate: true
multiline.match: after

(F) #3

Thanks for your reply @kvch

I ended up figuring out my issue. I made changes to the grok pattern and also added kv option. Just in case anyone else has a similar issue, the new grok pattern is below:

  if [type] == "api" {
    grok {
      match => {"message" => "%{TIMESTAMP_ISO8601:Timestamp} \[%{DATA:CID:int}] \[%{DATA:TID:int}] \[%{DATA:HClient}]\s(%{DATA:TName}) %{WORD:LogLevel} %{DATA:Msg}\s\[(?<questBody>(.*))]"}
      match => {"message" => "%{TIMESTAMP_ISO8601:Timestamp} \[%{DATA:CID:int}] \[%{DATA:TID:int}] \[%{DATA:HClient}]\s(%{DATA:TName}) %{WORD:LogLevel} %{GREEDYDATA:Msg}"}
      match => {"message" => "%{TIMESTAMP_ISO8601:Timestamp} \[%{DATA:CID:int}] \[%{DATA:TID:int}] \[%{DATA:HClient}]\s %{WORD:LogLevel} %{GREEDYDATA:Msg}"}
    }
    if [questBody] {
      kv {
        source => "questBody"
        value_split => ":"
        include_brackets => true
        trim_value => ","
        trim_key => "\",\[\]<>\{\}"
        remove_char_key => "\{\}\[\]\""
   }
  }
 }
}

(Noémi Ványi) #4

Thanks for sharing it with us!


(system) #5

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