Logstash parsing broken after upgrading from filebeat 5.6 to 7.6. Appears to be an issue with logs not getting tagged correctly

We recently upgraded our ELK stack and I realized we were still using filebeats 5.6 on our servers for log shipping. I'm testing out upgrading to 7.6 on a dev server. The upgrade itself went fine and it is still shipping logs but I noticed none of them seem to be showing up in kibana. I enabled ruby debug and the logs look totally different as they are coming in and they don't appear to be being parsed at all by logstash. Our logstash rules use the type field to match log types. For example, here is our logstash rule for logs that are tagged as syslog:

filter {
if [type] == "syslog" {
grok {
break_on_match => false
match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:[%{POSINT:syslog_pid}])?: %{GREEDYDATA:syslog_message}" }
match => { "syslog_message" => [ "^%{SPACE}%{WORD:sudo_requested_user}%{SPACE}:%{SPACE}TTY", "USER=%{WORD:sudo_user}", "COMMAND=%{GREEDYDATA:sudo_command}" ] }
match => { "syslog_message" => "Failed password for (invalid user |)%{USERNAME:username} from %{IP:src_ip} port %{BASE10NUM:port} ssh2" }
add_field => [ "received_at", "%{@timestamp}" ]
add_field => [ "received_from", "%{host}" ]
}
syslog_pri { }
date {
match => [ "syslog_timestamp", "MMM d HH:mm:ss", "MMM dd HH:mm:ss" ]
}
}
if [syslog_program] == "db_percona_backup" {
grok {
match => { "syslog_message" => "%{WORD:percona_backup_shard} %{WORD:percona_backup_status}" }
}
}
}

And here is our previous, working filebeat config:

filebeat.prospectors:

  • input_type: log
    paths:

    • /var/log/messages
    • /var/log/syslog
    • /var/log/auth.log
    • /var/log/cron
    • /var/log/messages
    • /var/log/secure
    • /var/log/dracut.log
    • /var/log/maillog
    • /var/log/mail.log
    • /var/log/yum.log
      document_type: syslog
  • input_type: log
    paths:

    • /var/log/haproxy.log
      document_type: haproxy
  • input_type: log
    paths:

    • /var/rails/benefits/current/log/logstash_production.log
    • /var/rails/benefits/current/log/logstash_production.log
    • /var/rails/ch-website/current/log/logstash_production.log
    • /var/rails/benefitkey/current/log/logstash_production.log
      document_type: rails_json
  • input_type: log
    paths:

    • /var/log/audit/*.log
      document_type: auditd
  • input_type: log
    paths:

    • /var/log/apache2/admin.log
    • /var/log/apache2/analytics.log
    • /var/log/apache2/api.log
    • /var/log/apache2/benefits.log
    • /var/log/apache2/broker.log
    • /var/log/apache2/carrier.log
    • /var/log/apache2/hrportal.log
    • /var/log/other_vhosts_access.log
    • /var/log/apache2/pcms.log
    • /var/log/apache2/*com.log
      document_type: apache
      output.logstash:
      hosts: ["ps-dev-elk.plansourcedev.com:5044"]
      ssl.certificate_authorities: ["/etc/pki/tls/certs/filebeat.crt"]
      timeout: 30

After upgrading to filebeat 7.6 and running into some issues, this is the new filebeat config I'm currently trying out but it's not tagging the log messages correctly with the type field:

filebeat.inputs:

  • type: log
    paths:

    • /var/log/messages
    • /var/log/syslog
    • /var/log/auth.log
    • /var/log/cron
    • /var/log/messages
    • /var/log/secure
    • /var/log/dracut.log
    • /var/log/maillog
    • /var/log/mail.log
    • /var/log/yum.log
      fields:
      type: syslog
      tags: ["syslog"]
  • type: log
    paths:

    • /var/log/haproxy.log
      fields:
      type: haproxy
  • type: log
    paths:

    • /var/rails/benefits/current/log/logstash_production.log
    • /var/rails/benefits/current/log/logstash_production.log
    • /var/rails/ch-website/current/log/logstash_production.log
    • /var/rails/benefitkey/current/log/logstash_production.log
      fields:
      type: rails_json
      tags: ["rails_json"]
  • type: log
    paths:

    • /var/log/audit/*.log
      fields:
      type: auditd
  • type: log
    paths:

    • /var/log/apache2/admin.log
    • /var/log/apache2/analytics.log
    • /var/log/apache2/api.log
    • /var/log/apache2/benefits.log
    • /var/log/apache2/broker.log
    • /var/log/apache2/carrier.log
    • /var/log/apache2/hrportal.log
    • /var/log/other_vhosts_access.log
    • /var/log/apache2/pcms.log
    • /var/log/apache2/*com.log
      fields:
      type: apache
      tags: ["apache"]

output.logstash:
hosts: ["ps-dev-elk.plansourcedev.com:5044"]
ssl.certificate_authorities: ["/etc/pki/tls/certs/filebeat.crt"]
timeout: 30

Here's an example ruby debug log message from the old version of filebeat that is still working:

{
"offset" => 703466488,
"syslog_program" => "CRON",
"syslog_message" => "pam_unix(cron:session): session closed for user test",
"received_at" => "2020-02-26T22:20:44.349Z",
"received_from" => "%{host}",
"syslog_severity_code" => 5,
"source" => "/var/log/auth.log",
"message" => "Feb 26 22:20:35 ps-test-util01 CRON[62395]: pam_unix(cron:session): session closed for user test",
"syslog_pid" => "62395",
"@timestamp" => 2020-02-26T22:20:35.000Z,
"input_type" => "log",
"beat" => {
"version" => "5.6.16",
"hostname" => "ps-test-util01.plansourcetest.com",
"name" => "ps-test-util01.plansourcetest.com"
},
"type" => "syslog",
"tags" => [
[0] "beats_input_codec_plain_applied"
],
"syslog_timestamp" => "Feb 26 22:20:35",
"syslog_facility_code" => 1,
"syslog_facility" => "user-level",
"syslog_severity" => "notice",
"@version" => "1",
"syslog_hostname" => "ps-test-util01"
}

and here's one from filebeat 7.6 that is not working and looks completely different:

{
"fields" => {
"type" => "syslog"
},
"log" => {
"offset" => 145468709,
"file" => {
"path" => "/var/log/secure"
}
},
"host" => {
"name" => "ps-dev-web01.plansourcedev.com"
},
"message" => "Jul 28 09:04:03 ps-dev-web01 sudo: pam_unix(sudo:session): session closed for user root",
"agent" => {
"version" => "7.6.0",
"hostname" => "ps-dev-web01.plansourcedev.com",
"type" => "filebeat",
"ephemeral_id" => "b29a0eaf-71de-4256-9624-268e12af6b10",
"id" => "f3149f8f-75fc-41bc-b781-6d0b4e90d319"
},
"@timestamp" => 2020-02-26T22:20:11.641Z,
"type" => "logs",
"tags" => [
[0] "syslog",
[1] "beats_input_codec_plain_applied"
],
"input" => {
"type" => "log"
},
"ecs" => {
"version" => "1.4.0"
},
"@version" => "1"
}

Any suggestions on how to get things working again with 7.6?

Also just noticed I'm getting these errors in the logstash log:

[2020-02-26T22:28:08,539][WARN ][logstash.outputs.elasticsearch][main] Could not index event to Elasticsearch. {:status=>400, :action=>["index", {:_id=>nil, :_index=>"logstash-2020.02.26", :routing=>nil, :_type=>"_doc"}, #<LogStash::Event:0x4548a9f1>], :response=>{"index"=>{"_index"=>"logstash-2020.02.26", "_type"=>"_doc", "_id"=>"vCCdg3ABQ1tpPHB5Scma", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"failed to parse field [log] of type [text] in document with id 'vCCdg3ABQ1tpPHB5Scma'. Preview of field's value: '{file={path=/var/log/secure}, offset=213788658}'", "caused_by"=>{"type"=>"illegal_state_exception", "reason"=>"Can't get text on a START_OBJECT at 1:35"}}}}}

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