Logstash CEF codec and ECS cannot parse 'rt' field throws an error

Elastic Stack Logstash
1

Without ECS, the 'rt' field could be parsed fine and mapped into 'deviceReceiptTime' field. But after enabling ECS in Logstash configuration it throws me an error in log ingesting. Could somebody guide me through this as I am new to Logstash and Elastic Stack

Error log:

Jul 27 04:03:33 siem-cmerp logstash[95486]: parse_cef_format_sgring("2022-07-27T12:03:33+08:00", nil) #!=> Text '2022-07-27T12:03:33+08:00' could not be parsed at index 0
Jul 27 04:03:33 siem-cmerp logstash[95486]: [2022-07-27T04:03:33,236][ERROR][logstash.codecs.cef      ][insight][123826a1a734cffe10ba61160d1569e3c5e2d3d6ff5fbbab4c8dc2459f2ac557] Failed to parse CEF timestamp value `2022-07-27T12:03:33+08:00` (Text '2022-07-27T12:03:33+08:00' could not be parsed at index 0)
Jul 27 04:03:33 siem-cmerp logstash[95486]: [2022-07-27T04:03:33,238][ERROR][logstash.codecs.cef      ][insight][123826a1a734cffe10ba61160d1569e3c5e2d3d6ff5fbbab4c8dc2459f2ac557] Failed to decode CEF payload. Generating failure event with payload in message field. {:exception=>LogStash::Codecs::CEF::InvalidTimestamp, :message=>"Not a valid CEF timestamp: `2022-07-27T12:03:33+08:00`", :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-cef-6.2.5-java/lib/logstash/codecs/cef.rb:556:in `normalize_timestamp'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-cef-6.2.5-java/lib/logstash/codecs/cef.rb:273:in `block in handle'", "org/jruby/ext/set/RubySet.java:630:in `each'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-cef-6.2.5-java/lib/logstash/codecs/cef.rb:271:in `handle'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-cef-6.2.5-java/lib/logstash/codecs/cef.rb:200:in `decode'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-udp-3.5.0/lib/logstash/inputs/udp.rb:164:in `inputworker'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-udp-3.5.0/lib/logstash/inputs/udp.rb:76:in `block in run'"], :original_data=>"2022-07-27T12:03:33+08:00 InsightCef CEF:0|CMERP|INSIGHT|1|1075168|Common Name Without Domain Name|High|externalId=36521852 smac=50:3e:aa:e4:19:ae src=10.108.102.60 spt=45788 dst=139.59.84.212 dpt=443 proto=TCP deviceInboundInterface=ens33 app=tls cs2Label=payload cs2=FgMDAFkCAABVAwM4N5hdUCvLofKbysVEcf+k9bA155z5ac3m7UlUEcPjJiCe1erzxPbJgcslod4yNJETNVYvzvC7bcu4iK86QQnfM8AsAAAN/wEAAQAACwAEAwABAhYDAwGpCwABpQABogABnzCCAZswggEgoAMCAQICCAmSp7UGRJsyMAoGCCqGSM49BAMDMBQxEjAQBgNVBAMTCXN5bmN0aGluZzAeFw0xNjA5MTIwNzQ3MDhaFw00OTEyMzEyMzU5NTlaMBQxEjAQBgNVBAMTCXN5bmN0aGluZzB2MBAGByqGSM49AgEGBSuBBAAiA2IABBZdFkrxGGvCsOuPiZlD2mjEhpoKt9/nBW4nyZhWriBHO0oAmiXwZPW+3b7uAzwpL6Y5KL+uoac1b3OTgvYtcmQPDCyvxfdcHkf1onnkWBX2fmzyVETofFsLphGpl/3lHaM/MD0wDgYDVR0PAQH/BAQDAgWgMB0GA1UdJQQWMBQGCCsGAQUFBwMBBggrBgEFBQcDAjAMBgNVHRMBAf8EAjAAMAoGCCqGSM49BAMDA2kAMGYCMQDEh1O8qY18xJ3ghSC5NhLWyzWoPE7AXUCDarXFB82wvwUOUdQ6e6CFFXfitKoSiQoCMQDXsQXAgGMXrogXWvQu3fOJZkBFtWAbVU1BjHDaDZtdqE9ruh8VBd8Cf99YuDRCP8UWAwMAswwAAK8DABdBBLwBs7xytgHz4BJgF7C5zO5X7QJcV6Cct2CpLLBYXk+PjlQ830g6pgVxOidwMGBmKI3wgyZcvAGqJQES4mh22NEGAwBmMGQCMG06bs6XkG3ZM9xJ2/TP0wsUiu0YFGOX/eruufdKdW1iLfj2PkiB+si6PSv2rDTisgIwK8mf+/92efdQbTvP0+qiWyZqVkUC0MzKtvuKdeVeTgUoDRxAkUOqTHTcWi8FFnwxFgMDAC4NAAAmAwECQAAeBgEGAgYDBQEFAgUDBAEEAgQDAwEDAgMDAgECAgIDAAAOAAAA cs3Label=threat_class cs3=Suspicious Network Interaction dvchost=Suri5a act=allowed deviceDirection=Inbound cs4Label=signature_techique_name cs4=Tls cs1Label=threat cs1=Common Name Without Domain Name cs5Label=sensor_id cs5=28 rt=2022-07-27T12:03:33+08:00"}
Jul 27 04:03:33 siem-cmerp logstash[95486]: [2022-07-27T04:03:33,352][ERROR][logstash.filters.ruby    ][insight][01a1cc7bfbee2e1c78dabaa8545d03bddd39d5955d46e0fb6e751da45d382514] Ruby 
exception occurred: undefined method `unpack1' for nil:NilClass {:class=>"NoMethodError", :backtrace=>["/usr/share/logstash/vendor/jruby/lib/ruby/stdlib/base64.rb:59:in `decode64'", "(ruby filter code):2:in `block in filter_method'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-ruby-3.1.8/lib/logstash/filters/ruby.rb:96:in `inline_script'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-ruby-3.1.8/lib/logstash/filters/ruby.rb:89:in `filter'", "/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:159:in `do_filter'", "/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:178:in `block in multi_filter'", "org/jruby/RubyArray.java:1821:in `each'", "/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:175:in `multi_filter'", "org/logstash/config/ir/compiler/AbstractFilterDelegatorExt.java:134:in `multi_filter'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:300:in `block in start_workers'"]}
Jul 27 04:03:33 siem-cmerp logstash[95486]: {
Jul 27 04:03:33 siem-cmerp logstash[95486]:       "@version" => "1",
Jul 27 04:03:33 siem-cmerp logstash[95486]:           "type" => "syslog",
Jul 27 04:03:33 siem-cmerp logstash[95486]:           "host" => {
Jul 27 04:03:33 siem-cmerp logstash[95486]:         "ip" => "10.108.201.243"
Jul 27 04:03:33 siem-cmerp logstash[95486]:     },
Jul 27 04:03:33 siem-cmerp logstash[95486]:           "tags" => [
Jul 27 04:03:33 siem-cmerp logstash[95486]:         [0] "_cefparsefailure",
Jul 27 04:03:33 siem-cmerp logstash[95486]:         [1] "insight",
Jul 27 04:03:33 siem-cmerp logstash[95486]:         [2] "_rubyexception",
Jul 27 04:03:33 siem-cmerp logstash[95486]:         [3] "_geoip_lookup_failure"
Jul 27 04:03:33 siem-cmerp logstash[95486]:     ],
Jul 27 04:03:33 siem-cmerp logstash[95486]:        "message" => "2022-07-27T12:03:33+08:00 InsightCef CEF:0|CMERP|INSIGHT|1|1075168|Common Name Without Domain Name|High|externalId=36521852 smac=50:3e:aa:e4:19:ae src=10.108.102.60 spt=45788 dst=139.59.84.212 dpt=443 proto=TCP deviceInboundInterface=ens33 app=tls cs2Label=payload cs2=FgMDAFkCAABVAwM4N5hdUCvLofKbysVEcf+k9bA155z5ac3m7UlUEcPjJiCe1erzxPbJgcslod4yNJETNVYvzvC7bcu4iK86QQnfM8AsAAAN/wEAAQAACwAEAwABAhYDAwGpCwABpQABogABnzCCAZswggEgoAMCAQICCAmSp7UGRJsyMAoGCCqGSM49BAMDMBQxEjAQBgNVBAMTCXN5bmN0aGluZzAeFw0xNjA5MTIwNzQ3MDhaFw00OTEyMzEyMzU5NTlaMBQxEjAQBgNVBAMTCXN5bmN0aGluZzB2MBAGByqGSM49AgEGBSuBBAAiA2IABBZdFkrxGGvCsOuPiZlD2mjEhpoKt9/nBW4nyZhWriBHO0oAmiXwZPW+3b7uAzwpL6Y5KL+uoac1b3OTgvYtcmQPDCyvxfdcHkf1onnkWBX2fmzyVETofFsLphGpl/3lHaM/MD0wDgYDVR0PAQH/BAQDAgWgMB0GA1UdJQQWMBQGCCsGAQUFBwMBBggrBgEFBQcDAjAMBgNVHRMBAf8EAjAAMAoGCCqGSM49BAMDA2kAMGYCMQDEh1O8qY18xJ3ghSC5NhLWyzWoPE7AXUCDarXFB82wvwUOUdQ6e6CFFXfitKoSiQoCMQDXsQXAgGMXrogXWvQu3fOJZkBFtWAbVU1BjHDaDZtdqE9ruh8VBd8Cf99YuDRCP8UWAwMAswwAAK8DABdBBLwBs7xytgHz4BJgF7C5zO5X7QJcV6Cct2CpLLBYXk+PjlQ830g6pgVxOidwMGBmKI3wgyZcvAGqJQES4mh22NEGAwBmMGQCMG06bs6XkG3ZM9xJ2/TP0wsUiu0YFGOX/eruufdKdW1iLfj2PkiB+si6PSv2rDTisgIwK8mf+/92efdQbTvP0+qiWyZqVkUC0MzKtvuKdeVeTgUoDRxAkUOqTHTcWi8FFnwxFgMDAC4NAAAmAwECQAAeBgEGAgYDBQEFAgUDBAEEAgQDAwEDAgMDAgECAgIDAAAOAAAA cs3Label=threat_class cs3=Suspicious Network Interaction dvchost=Suri5a act=allowed deviceDirection=Inbound cs4Label=signature_techique_name cs4=Tls cs1Label=threat cs1=Common Name Without Domain Name cs5Label=sensor_id cs5=28 rt=2022-07-27T12:03:33+08:00",
Jul 27 04:03:33 siem-cmerp logstash[95486]:     "@timestamp" => 2022-07-27T04:03:33.240160Z
Jul 27 04:03:33 siem-cmerp logstash[95486]: }

Logstash v8 configuration:

input {
  udp {
        port => 5524
        ecs_compatibility => v8
        codec => cef {}
        type => syslog
        tags => ["insight"]
  }
}
filter {
        date {
                match => [ "rt", "ISO8601" ]
                target => "@timestamp"
            }
        ruby {
           code => 'event.set("[cef][device_custom_string_2][decoded]", Base64.decode64(event.get("[cef][device_custom_string_2][value]")))'
             }
        mutate {
                gsub => [
                        "[event][severity]", "[\?#|-]", "",
                        "[cef][name]", "[\\\?#|-]", " ",
                        "[cef][device_custom_string_1][value]", "[\\\?#|-]", " ",
                        "[cef][device_custom_string_3][label]", "\_", " ",
                        "[cef][device_custom_string_4][value]", "[\_\=]", " ",
                        "[cef][device_custom_string_4][label]", "[\_]", " ",
                        "[cef][device_custom_string_5][label]", "[\_]", " "
                         ]
                }
        geoip {
                source => "[destination][ip]"
        }
}
output {
    elasticsearch {
         hosts => ["*censored*:9200"]
         index => "logs-insightcef-data-stream-test"
         user => "*censored*"
         password => "*censored*!"
         action => "create"
  }
  stdout {
        codec => rubydebug
}
}

Logstash pipeline configuration:

 - pipeline.id: insight
   path.config: "/etc/logstash/conf.d/insight-test.conf"
   pipeline.ecs_compatibility: v8
2

A simple configuration to reproduce this is

output { stdout { codec => rubydebug { metadata => false } } }
input {
    generator {
        count => 1
        lines => [
            '2022-07-26T12:03:33+08:00 InsightCef CEF:0|CMERP|INSIGHT|1|1075168|Common Name Without Domain Name|High|rt=2022-07-26T12:03:33+08:00',
            '2022-07-26T12:03:33+08:00 InsightCef CEF:0|CMERP|INSIGHT|1|1075168|Common Name Without Domain Name|High|smac=50:3e:aa:e4:19:ae'
        ]
        codec => cef
    }
}

with --pipeline.ecs_compatibility disabled both lines are parsed, but with the default ecs_compatability setting the first one gets that timestamp parsing error. The problem is that the codec tries to normalize the field as a timestamp (you would have the same problem for end and other timestamp fields). The timestamp normalizer is looking for something that matches

"MMM dd[ yyyy] HH:mm:ss[.SSSSSSSSS][.SSSSSS][.SSS][ zzz]"

From what I have read, the rt field should be formatted as "MMM dd yyyy HH:mm:ss or milliseconds since epoch (Jan 1st 1970)". It does not accept ISO8601 style formats. The parser expects a month name at the start of the timestamp string so when it gets a year it "could not be parsed at index 0".

Personally I think demanding a specific format for rt/end etc is A Bridge Too Far, but that's not my call.

To fix this, stop using a cef codec on the initial input. grok the rt= out of the message and parse it using a date filter, then mutate+gsub it out of the message. Then use a tcp output to send the event to a tcp input with a cef codec. An example of that is here. Do not try pipeline-to-pipeline communication, that ignores the codec setting.

3

I have found the solution to the issue prior to your reply and did not manage to update on this discussion. The root cause of this error is exactly about the timestamp format from the source of event logs I am ingesting from, just like what you suspected.

I have changed the format of 'rt' from ISO8601 into the "MMM dd HH:mm:ss" format and logstash was able to parse the logs successfully. It never occurred to me the problem was the timestamp format, because without ecs_compatibility => v8, the 'rt' field is mapped into deviceReceiptTime field successfully. But as I have read here (CEF codec plugin) regarding the mapping of CEF and ECS compatibility, the 'rt' field is mapped into @timestamp, and that is not the case without ecs_compatibility, thus led me to suspect the issue was with the timestamp format.

What I have done is from the source where I am ingesting logs from, I changed the format of timestamp in the code, and Logstash is able to parse the date and convert it into ISO8601 (at least that's what I understand from below log output:

Jul 28 08:55:34 siem-cmerp logstash[101367]:           "event" => {
Jul 28 08:55:34 siem-cmerp logstash[101367]:             "code" => "1065291",
Jul 28 08:55:34 siem-cmerp logstash[101367]:           "action" => "allowed",
Jul 28 08:55:34 siem-cmerp logstash[101367]:         "severity" => "High"
Jul 28 08:55:34 siem-cmerp logstash[101367]:     },
Jul 28 08:55:34 siem-cmerp logstash[101367]:        "@version" => "1",
Jul 28 08:55:34 siem-cmerp logstash[101367]:      "@timestamp" => 2022-07-28T08:55:31Z
Jul 28 08:55:34 siem-cmerp logstash[101367]: }

Thank you @Badger for your time in troubleshooting this matter. Your take on the timestamp format is exactly the problem to this issue.

4

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