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

Feature/java implementation #93

Closed
wants to merge 1 commit into from
Closed

Conversation

ph
Copy link
Contributor

@ph ph commented Jun 9, 2016

Not ready for production, do not use.

@ph
Copy link
Contributor Author

ph commented Jun 17, 2016

@talevy there is a faillings test in when the when the client authenticate with a secondary ca, I am looking at fixing this but You can do a first run :)

@ph
Copy link
Contributor Author

ph commented Jun 20, 2016

@talevy this PR need to run with logstash master.

@@ -2,3 +2,4 @@ source 'https://rubygems.org'

# Specify your gem's dependencies in logstash-mass_effect.gemspec
gemspec
gem "logstash-core", :path => "~/es/logstash"
Copy link

Choose a reason for hiding this comment

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

leaving a note here to remember we need this to go before merging

@ph
Copy link
Contributor Author

ph commented Jun 23, 2016

@talevy Can you take a second look?
@spinscale I have upgrade to netty 4.1.1, I had a few issues with the upgrade that the BeatsParser test catched and I have fixed all of them. I am still doing some test locally for freeing up the bytebuffer to make sure It doesnt have a leak.

compile 'io.netty:netty-tcnative-boringssl-static:1.1.33.Fork17'
compile 'org.apache.logging.log4j:log4j-api:2.6.1'
compile 'org.apache.logging.log4j:log4j-core:2.6.1'
compile 'org.lucee:javassist:3.9.0.GA'

Choose a reason for hiding this comment

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

thats not the origininal javassist package, try http://mvnrepository.com/artifact/org.javassist/javassist

@ph
Copy link
Contributor Author

ph commented Jun 30, 2016

I did another pass @spinscale !

READ_JSON(-1),
READ_DATA_FIELDS(-1);

private int value;

Choose a reason for hiding this comment

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

name it length?

@spinscale
Copy link

left some minor comments, but I like this. hope to get this into more testing soon! :)

@spinscale
Copy link

quick update: Be careful with jackson and dependencies.. I just checked out this issue in the rss plugin and I see a reference to afterburner already logstash-plugins/logstash-input-rss#21

@jordansissel
Copy link
Contributor

Failing to use this plugin:

% bin/logstash -e 'input { beats { } }'
fetched an invalid config {:config=>"input { beats { } }output { stdout { codec => rubydebug } }", :reason=>"Couldn't find any input plugin named 'beats'. Are you sure this is correct? Trying to load the beats input plugin resulted in this error: no such file to load -- vendor/jar-dependencies/logstash-input-beats-3.1.0.beta1", :level=>:error}

Noting the 'no such file to load', I checked a few things and everything seems OK to me:

% grep logstash-input-beats Gemfile*
Gemfile:gem "logstash-input-beats", "3.1.0.beta1", :path => "vendor/local_gems/18ae8921/logstash-input-beats-3.1.0.beta1-java"
Gemfile.jruby-1.9.lock:  remote: vendor/local_gems/18ae8921/logstash-input-beats-3.1.0.beta1-java
Gemfile.jruby-1.9.lock:    logstash-input-beats (3.1.0.beta1-java)
Gemfile.jruby-1.9.lock:  logstash-input-beats (= 3.1.0.beta1)!

^^^ Correct version installed, it seems.

And the file it should have tried to load does exist:

vendor/local_gems/18ae8921/logstash-input-beats-3.1.0.beta1-java/vendor/jar-dependencies/logstash-input-beats-3.1.0.beta1.jar

Weird?

require "logstash/util"
require "thread_safe"
require "vendor/jar-dependencies/logstash-input-beats-3.1.0.beta1.jar"
Copy link
Contributor

Choose a reason for hiding this comment

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

This causes Logstash to fail to load the plugin because the file is not found because it's the wrong path.

The .gemspec puts vendor/jar-dependencies into ruby's library path, so you can just do require "logstash-input-beats-3.1.0.beta1.jar" here. If I make this change, I can load this plugin into logstash.

@jordansissel
Copy link
Contributor

jordansissel commented Jul 12, 2016

If you throw garbage at a plain text beats input, you get all kinds of fun exceptions:

To reproduce:

% bin/logstash --log.level debug -e 'input { beats { port => 12345 } }'
...
% dd if=/dev/urandom bs=4k count=1 | nc localhost 12345

Sample exception logged by Logstash:

Jul 11, 2016 3:05:14 PM io.netty.channel.AbstractChannelHandlerContext invokeExceptionCaught
WARNING: An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
io.netty.handler.codec.DecoderException: java.lang.IllegalArgumentException: Illegal initial capacity: -1982301064
        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:442)
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
        at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:36)
        at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:339)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:339)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:393)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:742)
        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.IllegalArgumentException: Illegal initial capacity: -1982301064
        at java.util.HashMap.<init>(HashMap.java:448)
        at java.util.HashMap.<init>(HashMap.java:467)
        at org.logstash.beats.BeatsParser.decode(BeatsParser.java:125)
        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411)
        ... 9 more

@jordansissel
Copy link
Contributor

jordansissel commented Jul 12, 2016

Sending a MAX_INT as the json payload length causes fun errors>

Reproduction:

>> o = { "hello" => "world" }; TCPSocket.new("localhost", 12345).tap { |x| x.write(["1W", 1].pack("A*N")); x.write(["2J", 1, -1, o.to_json].pack("A*NNA*")); }.close

Error: io.netty.handler.codec.DecoderException: java.lang.NegativeArraySizeException

Full output

15:19:36.794 [nioEventLoopGroup-3-2] ERROR org.logstash.beats.BeatsHandler - Exception
io.netty.handler.codec.DecoderException: java.lang.NegativeArraySizeException
        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:442) ~[netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248) ~[netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:36) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:339) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:339) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:393) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:742) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145) [netty-all-4.1.1.Final.jar:4.1.1.Final]
        at java.lang.Thread.run(Thread.java:745) [?:1.8.0_72]
Caused by: java.lang.NegativeArraySizeException
        at org.logstash.beats.BeatsParser.decode(BeatsParser.java:193) ~[logstash-input-beats-3.1.0.beta1.jar:?]
        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411) ~[netty-all-4.1.1.Final.jar:4.1.1.Final]
        ... 9 more

@jordansissel
Copy link
Contributor

Hilarious things happen when Logstash runs out of file descriptors. I triggered this scenario by simply opening lots of connections.

>> 10000.times.collect { TCPSocket.new("localhost", 12345) }.map(&:close)

build/
.idea
.gradle
null
Copy link
Contributor

Choose a reason for hiding this comment

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

null? hah.

@jordansissel
Copy link
Contributor

Very poorly-scienced performance comparison on my 1-core VM

% (cd logstash-5.0.0-alpha4-with-new-beats; bin/logstash-plugin list --verbose | grep beats; bin/logstash -e 'input { beats { port => 12345 } } output { stdout { codec => dots } }'  | pv -War > /dev/null)
logstash-input-beats (3.1.0.beta1)
...
[13.5KiB/s] [9.37KiB/s]

Peak was around 13.5Keps (this PR)

% (cd logstash-5.0.0-alpha4; bin/logstash-plugin list --verbose | grep beats; bin/logstash -e 'input { beats { port => 12345 } } output { stdout { codec => dots } }'  | pv -War > /dev/null)
logstash-input-beats (3.0.3)
...
[11.2KiB/s] [4.55KiB/s]

Release (5.0.0-alpha4) beats input peaks at 11.2Keps.

filebeat.yml

% egrep -v '^\s*#|^\s*$' filebeat.yml
filebeat:
  prospectors:
    -
      paths:
        - /var/log/*.log
      input_type: stdin
output:
  logstash:
    hosts: ["localhost:12345"]
shipper:
logging:
  files:
    rotateeverybytes: 10485760 # = 10MB

@jordansissel
Copy link
Contributor

Same test as above with a 2-core VM (same physical machine)

  • this pr: ~21Keps
  • version 3.0.3: ~18Keps

I need to test against older versions also.

@jordansissel
Copy link
Contributor

I also get this sometimes when shutting down:

java.util.concurrent.RejectedExecutionException: event executor terminated

@ph
Copy link
Contributor Author

ph commented Jul 18, 2016

answering @jordansissel's comment here.

java.util.concurrent.RejectedExecutionException: event executor terminated I think this is due to the idle check execution pool, I was able to get this error in tests.

Concerning the test what did you use to generate the events, Filebeat from stdin?

@jordansissel
Copy link
Contributor

jordansissel commented Jul 18, 2016

@ph yeah I used filebeat from stdin

  (seq 21000000; sleep 10) | ./filebeat

@ph
Copy link
Contributor Author

ph commented Jul 18, 2016

@jordansissel My test were done with logstash using all available core, the null output and generator beats which just send a infinite number of events. The stats were gathered at the sending end using libbeat http server. The metric was the number of events ack per seconds from a 30s window. IIRC.

@ph
Copy link
Contributor Author

ph commented Jul 18, 2016

I am investigating the leak that @talevy has found when running the code locally, with the LeakDetector set to Advanced.

@ph
Copy link
Contributor Author

ph commented Jul 18, 2016

@jordansissel still using stdout represent more a real world case. :)

@ph
Copy link
Contributor Author

ph commented Jul 18, 2016

@jordansissel Concerning the Number of FD and when we send garbage, would you be OK to do that in another PR, this one is starting to be pretty big :)

@ph
Copy link
Contributor Author

ph commented Jul 18, 2016

@jordansissel Can you use pipelining on the beat side under the logstash output configuration?
All the test we did was using 5 for the value, I don't think this option is on by default.

output.logstash:
  compression_level: 3
  hosts:
    - localhost:5044
  pipelining: 5

@talevy
Copy link

talevy commented Jul 19, 2016

LGTM.

I think this should be merged into master as is and we can open up new issues around @jordansissel to keep track of those separately: #93 (comment)

@suyograo
Copy link
Contributor

+1, this PR is getting huge as is.

@ph needs a rebase though

Motivation:

The core of Logstash is using more and more java instead of ruby for performance reason and scalability.
This PR introduce a lot of internal changes in the plugins and move from ruby to a pure java implementation using the Netty 4
Framework.

Also the connection model of this plugin has changed from a blocking to a non blocking implementation.
The changes should be backward compatible with the previous settings and will work for both LSF and Filebeat client.
@ph
Copy link
Contributor Author

ph commented Jul 19, 2016

I've created issues from @jordansissel comments:

#101, #100, #99, #98

@elasticsearch-bot
Copy link

Pier-Hugues Pellerin merged this into the following branches!

Branch Commits
master 01e70cf

@ph ph changed the title [WIP] Feature/java implementation Feature/java implementation Jul 19, 2016
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.

6 participants