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

Fix: log error when SSL context building fails #402

Merged
merged 13 commits into from
Dec 1, 2020

Conversation

kares
Copy link
Contributor

@kares kares commented Nov 27, 2020

There's several changes to make sure plugin provides better user-experience when it comes to logging.
The main motivator for the change set are key issues such as java.lang.IllegalArgumentException: File does not contain valid private key which are only logged upstream at a debug level (see #400).

On LS 7.8 / 7.9 the output when key has invalid format (or a ssl_xxx related configuration issue looks like):
(one needs to use --log.level debug to find out what the issue was)

[2020-11-27T15:40:32,191][INFO ][logstash.javapipeline    ][main] Pipeline Java execution initialization time {"seconds"=>0.52}
[2020-11-27T15:40:32,211][INFO ][logstash.inputs.beats    ][main] Starting input listener {:address=>"0.0.0.0:5044"}
[2020-11-27T15:40:32,308][ERROR][logstash.inputs.beats    ][main] SSL configuration invalid {:message=>"File does not contain valid private key: /home/kares/workspace/work/elastic/plugins/logstash-input-beats/cert-bundle/logstash.key"}
[2020-11-27T15:40:32,485][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-11-27T15:40:32,652][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
[2020-11-27T15:40:37,717][INFO ][logstash.runner          ] Logstash shut down.
[2020-11-27T15:40:37,730][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemExit) exit

Thus to improve the logger experience there's 3 set of changes:

[2020-11-30T12:53:38,997][INFO ][org.logstash.beats.BeatsHandler][main][beats-tls] [local: 0.0.0.0:5044, remote: 192.168.122.59:57466] Handling exception: io.netty.handler.codec.DecoderException: javax.net.ssl.SSLHandshakeException: General SSLEngine problem (caused by: java.security.cert.CertPathValidatorException: Path does not chain with any of the trust anchors)

resolves #400

[2020-11-30T12:53:38,997][INFO
][org.logstash.beats.BeatsHandler][main][beats-tls] [local:
0.0.0.0:5044, remote: 192.168.122.59:57466] Handling exception:
io.netty.handler.codec.DecoderException:
javax.net.ssl.SSLHandshakeException: General SSLEngine problem (caused
by: java.security.cert.CertPathValidatorException: Path does not chain
with any of the trust anchors)
@kares kares marked this pull request as ready for review November 30, 2020 12:32
@robbavey robbavey self-requested a review November 30, 2020 20:02
Copy link
Contributor

@robbavey robbavey left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for doing this! Just a few minor comments to clarify/improve consistency of some of the logging statements

end
if @ssl
if @ssl_key.nil? || @ssl_key.empty?
configuration_error "Missing required setting ssl_key => ... (due ssl => true)"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe could be reworded a little?

Suggested change
configuration_error "Missing required setting ssl_key => ... (due ssl => true)"
configuration_error "ssl_key => is a required setting when ssl=>true is configured"

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks, fine by me - what I was trying is to be a bit similar to the generic (required) parameter validation:

Missing a required setting for the beats input plugin:

  input {
    beats {
      port => # SETTING MISSING
      ...
    }
  }

lib/logstash/inputs/beats.rb Outdated Show resolved Hide resolved
lib/logstash/inputs/beats.rb Outdated Show resolved Hide resolved
lib/logstash/inputs/beats.rb Outdated Show resolved Hide resolved
lib/logstash/inputs/beats.rb Outdated Show resolved Hide resolved
.setProtocols(convert_protocols)
.setCipherSuites(normalized_ciphers)
rescue java.lang.IllegalArgumentException => e
@logger.error("SSL configuration invalid", :message => e.message)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Backtrace useful here?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

these are plugin 'owned' exceptions but it won't hurt to have a trace with debug logging


private static final int MAX_CAUSE_NESTING = 10;

private static Throwable extractCause(final Throwable ex, final int nesting) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could also use a slow "pointer"/fast "pointer" to detect exception loops, if an exception loop is common for this kind of error, but this is ok too if not

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

have checked this manually enforcing a TLS certificate validation failure - which gets us 4 levels of nested causes.
at this point I am not sure loops are common just wanted to make sure we do not accidentally end up looping too much here, esp. as these are considered non-fatal and won't halt plugin execution.

imho, what's important is that we try the extraction since the info logging the plugin did previously was not providing useful information on the 'real' cause + also gave 'unclear' logging based on the following condition:

cause.getMessage() == null ? cause.getClass().toString() : cause.getMessage()
which made me previously believe we had a javax.net.ssl.SSLHandshakeException: General SSLEngine problem around here while in fact it was wrapped in a io.netty.handler.codec.DecoderException with "javax.net.ssl.SSLHandshakeException: General SSLEngine problem" as the message.

the whole exception stack is later printed by Netty's logger.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Makes sense - I only asked about Exception loops because I encountered them working on the JMS plugin, and added a guard against them.

Copy link
Contributor

@robbavey robbavey left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, assuming travis (eventually) is green

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

key fatal error not printed with default info level
3 participants