search

logstash-plugins / logstash-filter-grok

Grok plugin to parse unstructured (log) data into something structured.
https://www.elastic.co/guide/en/logstash/current/plugins-filters-grok.html
Apache License 2.0
124 stars 97 forks source link

Fix mutex exceptions #98

Closed andrewvc closed 7 years ago

andrewvc commented 7 years ago

Fix Uncaught Mutex Interrupt Exceptions

The TimeoutEnforcer used ruby's Mutex class which is interruptible and throws a special exception. This switches the code to use ReentrantLock (which JRuby's Mutex is based on) directly, and use ReentrantLock.lock instead of ReentrantLock.lockInterruptibly

This also adds a small note about the placement of thread.interrupted.

Fixes https://github.com/logstash-plugins/logstash-filter-grok/issues/97

This also makes dangerous TimeoutEnforcer methods private

Some timeout enforcer methods must be called in a specific sequence. This makes these methods explicitly private in order to prevent future programmers from attempting to use them directly

guyboertje commented 7 years ago

@andrewvc Did you consider adding a multi-threaded version of the simple test that you added when the feature was first added?

jordansissel commented 7 years ago

Eyeballed the code and talked through it with @andrewvc over zoom. LGTM.

@guyboertje I agree we should add some tests that try and trigger concurrency problems. A future todo item? :)

andrewvc commented 7 years ago

@guyboertje yes, thanks for asking! It's a tricky subject with concurrency problems. For instance, in a recent Java Specialist's newletter, the sample problem was entirely un-reproducible on the author's mac! It had to be run on a different server. So, I would say this type of testing faces a unique challenge. The absence of evidence is not evidence of absence.

I agree with @jordansissel that we should add some tests to help find these things, but it's a reallly tricky thing to do right. I think its best to try to reason through these problems using knowledge of the JMM as a first pass.

I think it would generally be better for logic like this to be written in Java instead of JRuby, as Java has more clearly defined exceptions and concurrency behavior. For instance, this bug would not have existed in Java because we would have been forced to write a catch block for this exception.

Maybe if we do rewrite Grok in Java one day we can do that. If we get another error in this section of code I think we should add some more stress tests.

guyboertje commented 7 years ago

I did look at the original code and this PR - LGTM.

I must confess though, that most of the time I was wondering whether the original solution is too complex - but that is a discussion for a later time and may go away entirely if we leverage the Ingest Node Grok internals.

elasticsearch-bot commented 7 years ago

Andrew Cholakian merged this into the following branches!

Branch Commits
master 6f72be63a7d2f509ff65dd7112615970a584b452, 2c9756efd0d52cf5370a0978d9429af1d6ddd2d2, 565126116d55a8833810a926c4597f8c8188b9f2
PhaedrusTheGreek commented 6 years ago

In what version can we find this fix? I'm seeing the comment about 3.2.4, however I have a report of this error in 3.4.2:

[2017-11-22T08:52:52,120][FATAL][logstash.runner ] An unexpected error occurred! {:error=>#<InterruptedRegexpError: Regexp Interrupted>, :backtrace=>["org/jruby/RubyRegexp.java:1657:in `=~'", "(eval):541319:in `initialize'", "org/jruby/RubyArray.java:1613:in `each'", "(eval):541296:in `initialize'", "org/jruby/RubyProc.java:281:in `call'", "(eval):541363:in `initialize'", "org/jruby/RubyArray.java:1613:in `each'", "(eval):541360:in `initialize'", "org/jruby/RubyProc.java:281:in `call'", "(eval):36626:in `filter_func'",  ...