Beats plugin will not start with "cipher not found"

Elastic Stack Logstash
1

ES 6.1.1
Kibana 6.1.1
Beats 6.1.2
All on Ubuntu 16.0.4 LTS

When upgrading Logstash from 5.6 to 6.1, I am unable to use SSL when defining the beats plugin, it complains that the cipher is not available, and Logstash will not start.

I found and tried the solution in topic https://discuss.elastic.co/t/problem-with-cipher-in-beat-input/67841, which did not help.

  • mkdir /usr/share/logstash/tmp
  • chown logstash /usr/share/logstash/tmp
  • chgrp logstash /usr/share/logstash/tmp
  • chmod 0775 /usr/share/logstash/tmp
  • modifying jvm.options and specifying -Dio.netty.native.workdir=/usr/share/logstash/tmp

I am using the Oracle JVM, and I found the solution in topic Logstash TLS with x-pack error registering plugin (Cipher is not available) 6.x, which does not seem to be applicable - Logstash 5.6 has no problem with AES_256 ciphers - I actually removed all ciphers but AES_256 to test this.

All other inputs (non-SSL) instantiate fine, outputs to logstash

Beats input stanza, (working fine in 5.6):

beats {
    port => 5044
    ssl => true
    ssl_certificate_authorities => ["/etc/ssl/xxx.pem"]
    ssl_certificate => "/etc/ssl/xxx.xxx.xxx.pem"
    ssl_key => "/etc/ssl/xxx.xxx.xxx.key"
    ssl_verify_mode => "force_peer"
    cipher_suites => ["TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384", "TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384", "TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384", "TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384"]
  }

Error on Logstash 6.1.3:

[2018-01-30T18:45:23,753][ERROR][logstash.pipeline ] Error registering plugin {:pipeline_id=>"main", :plugin=>"<LogStash::Inputs::Beats port=>5044, ssl=>true, ssl_certificate_authorities=>["/etc/ssl/xxx.pem"], ssl_certificate=>"/etc/ssl/xxx.xxx.xxx.pem", ssl_key=>"/etc/ssl/xxx.xxx.xxx.key", ssl_verify_mode=>"force_peer", id=>"a32f008bdfc78d72769ea669266b45cc0f21c19f4e18f292cf4b43882bca4436", enable_metric=>true, codec=><LogStash::Codecs::Plain id=>"plain_fbd31f65-e1b7-47f1-86c2-7a3782720bd0", enable_metric=>true, charset=>"UTF-8">, host=>"0.0.0.0", include_codec_tag=>true, ssl_handshake_timeout=>10000, tls_min_version=>1, tls_max_version=>1.2, cipher_suites=>["TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384", "TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384", "TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256", "TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256", "TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384", "TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384", "TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256", "TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256"], client_inactivity_timeout=>60, executor_threads=>32>", :error=>"Cipher TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384 is not available", :thread=>"#<Thread:0x56c6d23b@/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:245 run>"}
[2018-01-30T18:45:32,661][WARN ][logstash.runner ] SIGTERM received. Shutting down the agent.
[2018-01-30T18:45:33,634][ERROR][logstash.pipeline ] Pipeline aborted due to error {:pipeline_id=>"main", :exception=>#<LogStash::ConfigurationError: Cipher TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384 is not available>, :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/lib/logstash/inputs/beats.rb:170:in create_server'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/lib/logstash/inputs/beats.rb:158:in register'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:343:in register_plugin'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:354:in block in register_plugins'", "org/jruby/RubyArray.java:1734:in each'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:354:in register_plugins'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:510:in start_inputs'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:401:in start_workers'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:288:in run'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:248:in block in start'"], :thread=>"#<Thread:0x56c6d23b@/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:245 run>"}
[2018-01-30T18:45:33,639][ERROR][logstash.agent ] Failed to execute action {:id=>:main, :action_type=>LogStash::ConvergeResult::FailedAction, :message=>"Could not execute action: LogStash::PipelineAction::Create/pipeline_id:main, action_result: false", :backtrace=>nil}

Many thanks in advance for any assistance!

2

Started logstash with debug logging. Grep for "netty" and found this:

[DEBUG][io.netty.util.internal.PlatformDependent] -Dio.netty.tmpdir: /tmp

Added this line to jvm.options (kept the workdir line from above)

-Dio.netty.tmpdir=/usr/share/logstash/tmp

and now got this in the debug log:

...
[DEBUG][io.netty.util.internal.PlatformDependent] -Dio.netty.tmpdir: /usr/share/logstash/tmp
...
[DEBUG][io.netty.handler.ssl.OpenSsl] netty-tcnative not in the classpath; OpenSslEngine will be unavailable.
...
3

Ran strace -Ff -tt bin/logstash -f /etc/logstash/conf.d/logstash.conf 2>&1 | tee strace-logstash.log

I'd post the 78MB file, but it's kinda long

of note in the log, when running grep "tcnative" strace-logstash.log is that logstash finds and reads the tcnative jar

[pid 12803] 19:29:11.549241 stat("/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/vendor/jar-dependencies/io/netty/netty-tcnative-boringssl-static/2.0.7.Final/netty-tcnative-boringssl-static-2.0.7.Final.jar", {st_mode=S_IFREG|0644, st_size=2766507, ...}) = 0
    [pid 12803] 19:29:11.549605 stat("/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/vendor/jar-dependencies/io/netty/netty-tcnative-boringssl-static/2.0.7.Final/netty-tcnative-boringssl-static-2.0.7.Final.jar", {st_mode=S_IFREG|0644, st_size=2766507, ...}) = 0
    [pid 12803] 19:29:11.549801 stat("/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/vendor/jar-dependencies/io/netty/netty-tcnative-boringssl-static/2.0.7.Final/netty-tcnative-boringssl-static-2.0.7.Final.jar", {st_mode=S_IFREG|0644, st_size=2766507, ...}) = 0
    [pid 12803] 19:29:11.841321 stat("/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/vendor/jar-dependencies/io/netty/netty-tcnative-boringssl-static/2.0.7.Final/netty-tcnative-boringssl-static-2.0.7.Final.jar",  <unfinished ...>
    [pid 12803] 19:29:11.841418 stat("/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/vendor/jar-dependencies/io/netty/netty-tcnative-boringssl-static/2.0.7.Final/netty-tcnative-boringssl-static-2.0.7.Final.jar",  <unfinished ...>
    [pid 12803] 19:29:11.841510 open("/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-input-beats-5.0.6-java/vendor/jar-dependencies/io/netty/netty-tcnative-boringssl-static/2.0.7.Final/netty-tcnative-boringssl-static-2.0.7.Final.jar", O_RDONLY <unfinished ...>
    [pid 12803] 19:29:11.842145 <... read resumed> "-tcnative-boringssl-static/pom.p"..., 128) = 128

Anybody?

4

Performed bare-metal rebuild. Issue is gone. Unable to reproduce.

5

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