Logstash v5.6.3 won't start if debug logging is on

Elastic Stack Logstash
1

Hello,

I am running Logstash on Ubuntu 14.04 in AWS. Here are my config details:

$ grep -E -v '^#|^$' /etc/logstash/logstash.yml
node.name: logstash
path.data: /var/lib/logstash
path.config: /etc/logstash/conf.d
config.debug: true
log.level: debug
path.logs: /var/log/logstash
$
$ cat /etc/logstash/conf.d/*.conf
#
# This file is managed by Ansible - do not edit.
#
input {
  beats {
    port => 5044
  }
}
#
# This file is managed by Ansible - do not edit.
#
input {
  syslog {
    port => 5000
    type => syslog
  }
}
#
# This file is managed by Ansible - do not edit.
#
filter {
  if [type] == "syslog" {  
    grok {
      match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }
      add_field => [ "received_at", "%{@timestamp}" ]
      add_field => [ "received_from", "%{host}" ]
    }
    date {
      match => [ "syslog_timestamp", "MMM  d HH:mm:ss", "MMM dd HH:mm:ss" ]
    }
  }
}
#
# This file is managed by Ansible - do not edit.
#
output {
  elasticsearch {
    hosts => [ "elasticsearch:9200" ]
    index => "%{[@metadata][type]}-%{+YYYY.MM.dd}"
    document_type => "%{[@metadata][type]}"
    template_overwrite => "true"
  }
}
$

There are no backup files in /etc/logstash/conf.d. When I start Logstash I get these messages in /var/log/logstash/logstash-plain.log:

[2017-10-13T04:01:14,484][INFO ][logstash.pipeline        ] Starting pipeline {"id"=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>500}
[2017-10-13T04:01:14,495][ERROR][logstash.pipeline        ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {"exception"=>"undefined method `to_hash' for []:Array", "backtrace"=>["(eval):70:in `filter_func'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:398:in `filter_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:379:in `worker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:342:in `start_workers'"]}
[2017-10-13T04:01:14,505][ERROR][logstash.pipeline        ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {"exception"=>"undefined method `to_hash' for []:Array", "backtrace"=>["(eval):70:in `filter_func'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:398:in `filter_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:379:in `worker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:342:in `start_workers'"]}
[2017-10-13T04:01:14,511][ERROR][logstash.pipeline        ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {"exception"=>"undefined method `to_hash' for []:Array", "backtrace"=>["(eval):70:in `filter_func'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:398:in `filter_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:379:in `worker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:342:in `start_workers'"]}
[2017-10-13T04:01:14,516][ERROR][logstash.pipeline        ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {"exception"=>"undefined method `to_hash' for []:Array", "backtrace"=>["(eval):70:in `filter_func'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:398:in `filter_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:379:in `worker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:342:in `start_workers'"]}
[2017-10-13T04:01:14,567][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<NoMethodError: undefined method `to_hash' for []:Array>, :backtrace=>["(eval):70:in `filter_func'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:398:in `filter_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:379:in `worker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:342:in `start_workers'"]}

and then Logstash dies. This started happening after I upgraded from v5.6.2 to v5.6.3.

Please note, if I disable debug logging like so (in /etc/logstash/logstash.yml):

config.debug: false
log.level: info

then Logstash starts without issues.

Any insight would be highly appreciated.

Thank you,
Sergey

2

Sergey, I had similar issue. After doing some investigation and searching I have found the "Release notes" for this Logstash version and... - "Known Issue: Running Logstash with log level set to debug will cause the pipeline to crash"
Downgraded to previous version (5.6.2) and it works well.

3

Pavel, thank you so much for the information. Sounds like a bug Elastic needs to fix.