Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

improved logging when pipeline terminates by error #12274

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

jsvd
Copy link
Member

@jsvd jsvd commented Sep 24, 2020

What does this PR do?

Expose the exceptions when a pipeline terminates, either from a worker exception or plugin register error.

Why is it important/What is the impact to the user?

Users with errors in their pipelines must enable the debug flag to know why their pipeline isn't working.

Checklist

  • My code follows the style guidelines of this project
  • I have commented my code, particularly in hard-to-understand areas
  • I have made corresponding changes to the documentation
  • I have made corresponding change to the default configuration files (and/or docker env variables)
  • I have added tests that prove my fix is effective or that my feature works

Author's Checklist

How to test this PR locally

Verify that a pipeline logs the cause of its termination, when the error happens:

  1. at plugin register time (e.g. raise exception in ruby filter's init setting)
  2. pipeline validation time (e.g. start pipeline with syntax error or missing a plugin's required option)
  3. when a worker crashes (e.g. edit a filter plugin to raise exception in filter(events))

Related issues

fixes #12232

Use cases and Logs

Before:

❯ docker run --rm -it -e XPACK_MONITORING_ENABLED=false logstash:7.9.1 bin/logstash -e "filter { ruby { init => 'throw(\"hey\")' code => ''} }" --log.level=warn
2020/09/29 08:45:49 Setting 'xpack.monitoring.enabled' from environment.
Sending Logstash logs to /usr/share/logstash/logs which is now configured via log4j2.properties
[2020-09-29T08:46:07,880][WARN ][logstash.config.source.multilocal] Ignoring the 'pipelines.yml' file because modules or command line options are specified
[2020-09-29T08:46:10,359][ERROR][logstash.agent           ] Failed to execute action {:id=>:main, :action_type=>LogStash::ConvergeResult::FailedAction, :message=>"Could not execute action: PipelineAction::Create<main>, action_result: false", :backtrace=>nil}
[2020-09-29T08:46:15,560][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemExit) exit

After:

❯ bin/logstash -e "filter { ruby { init => 'throw(\"hey\")' code => ''} }" --log.level=warn 
Using JAVA_HOME defined java: /Users/joaoduarte/.jenv/versions/11.0
Sending Logstash logs to /Users/joaoduarte/elastic/logstash/logs which is now configured via log4j2.properties
[2020-09-29T09:45:14,438][WARN ][logstash.config.source.multilocal] Ignoring the 'pipelines.yml' file because modules or command line options are specified
[2020-09-29T09:45:15,951][ERROR][logstash.javapipeline    ][main] Pipeline terminated by error {:pipeline_id=>"main", :exception=>UncaughtThrowError, :message=>"uncaught throw \"hey\"", :backtrace=>["org/jruby/RubyKernel.java:1204:in `throw'", "(ruby filter init):1:in `register'", "org/jruby/RubyKernel.java:1048:in `eval'", "/Users/joaoduarte/elastic/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-ruby-3.1.5/lib/logstash/filters/ruby.rb:58:in `register'", "org/logstash/config/ir/compiler/AbstractFilterDelegatorExt.java:75:in `register'", "/Users/joaoduarte/elastic/logstash/logstash-core/lib/logstash/java_pipeline.rb:231:in `block in register_plugins'", "org/jruby/RubyArray.java:1809:in `each'", "/Users/joaoduarte/elastic/logstash/logstash-core/lib/logstash/java_pipeline.rb:230:in `register_plugins'", "/Users/joaoduarte/elastic/logstash/logstash-core/lib/logstash/java_pipeline.rb:565:in `maybe_setup_out_plugins'", "/Users/joaoduarte/elastic/logstash/logstash-core/lib/logstash/java_pipeline.rb:243:in `start_workers'", "/Users/joaoduarte/elastic/logstash/logstash-core/lib/logstash/java_pipeline.rb:188:in `run'", "/Users/joaoduarte/elastic/logstash/logstash-core/lib/logstash/java_pipeline.rb:137:in `block in start'"], "pipeline.sources"=>["config string"], :thread=>"#<Thread:0x34caad83 run>"}
[2020-09-29T09:45:15,984][ERROR][logstash.agent           ] Failed to execute action {:pipeline_id=>:main, :action=>"Create", :message=>"Could not execute action: PipelineAction::Create<main>, action_result: false", :backtrace=>nil}
[2020-09-29T09:45:21,262][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemExit) exit

@jsvd jsvd added the bug label Sep 24, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Pipeline startup errors hidden from user since 7.8.1
2 participants