JRuby/Netrc Issues

[IrateNinja]

Using the slack output plugin causes an exception.

bin/logstash -e '
input { stdin { codec => json } }
output { slack { url => "http://requestb.in/116n7581" } }'

Results In:

Unhandled exception {:exception=>#<Netrc::Error: Permission bits for '/home/xxx/.netrc' should be 0600, but are 644>, :stacktrace=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:45:in `check_permissions'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:52:in `read'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:284:in `parse_url_with_auth'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:175:in `execute'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:41:in `execute'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient.rb:69:in `post'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-slack-0.1.0/lib/logstash/outputs/slack.rb:64:in `receive'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/outputs/base.rb:88:in `handle'", "(eval):22:in `output_func'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:244:in `outputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:166:in `start_outputs'"], :level=>:warn}

The fire does have 0600 permissions:

$ ls -la /home/xxx/.netrc
-rw------- 1 xxx xxx 0 May 28 22:23 /home/xxx/.netrc
-rw------- 1 xxx xxx 0 May 28 22:23 /home/xxx/.netrc

Deleting the file (according to the netrc gem docs/source) should just ignore it, but instead throws a different exception

Unhandled exception {:exception=>#<SystemCallError: Unknown error - Unknown Error (0) - /home/xxx/.netrc>, :stacktrace=>["org/jruby/RubyFile.java:865:in `stat'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:43:in `check_permissions'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:52:in `read'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:284:in `parse_url_with_auth'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:175:in `execute'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:41:in `execute'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient.rb:69:in `post'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-slack-0.1.0/lib/logstash/outputs/slack.rb:64:in `receive'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/outputs/base.rb:88:in `handle'", "(eval):22:in `output_func'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:244:in `outputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:166:in `start_outputs'"], :level=>:warn}

Version Details Logstash 1.5

$ java -version
java version "1.8.0_45"
Java(TM) SE Runtime Environment (build 1.8.0_45-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode)
$ /opt/logstash/vendor/jruby/bin/jruby -v
jruby 1.7.19 (1.9.3p551) 2015-01-29 20786bd on Java HotSpot(TM) 64-Bit Server VM 1.8.0_45-b14 +jit [linux-amd64]

[lvh]

Do you have a .jrubyrc file laying around in that directory it's executing from? (Might wanna check the entire rootfs for jrubyrc files.)

[lvh]

Specifically, I'm conjecturing there's native.enabled=false or cext.enabled=false somewhere. (That is not an acceptable failure mode, though :))

[lucashenning]

I have the same problem with a logstash rest filter plugin which uses the same implementation of rest-client. Could this be caused by JRuby? Did you manage to solve it?

Here is my exception:

Exception in filterworker {"exception"=>#<SystemCallError: Unknown error - Unknown Error (0) - /home/xxx/.netrc>, "backtrace"=>[
    "org/jruby/RubyFile.java:865:in `stat'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:43:in `check_permissions'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:52:in `read'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:284:in `parse_url_with_auth'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:175:in `execute'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:41:in `execute'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/resource.rb:54:in `get'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-rest-0.1.0/lib/logstash/filters/rest.rb:50:in `filter'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/filters/base.rb:162:in `multi_filter'", 
    "org/jruby/RubyArray.java:1613:in `each'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/filters/base.rb:159:in `multi_filter'", "(eval):41:in `filter_func'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:219:in `filterworker'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:156:in `start_filters'"
], :level=>:error}

(Logstash 1.5, JRuby 1.7.19 (1.9.3p551), Java 1.8.0_45)

[lvh]

I haven't reproduced, and haven't heard back from @gdcbyers. I recommend you try the same diagnostic I suggested, though.

[IrateNinja]

I have looked more closely at my installation and found no trace of a .jrubyrc file anywhere. Logstash was installed from the official package from the official repo. Running jruby --properties revealed that the default is native.enabled=true and cext.enabled=false. I tried adding it using LS_JAVA_OPTS="-Djruby.cext.enabled=true" /opt/logstash/bin/logstash -e 'input { stdin { codec => json } } output { slack { url => "http://requestb.in/1jwxzzk1" } }' but still have the same issues. Not sure where to go from here.

[lvh]

Hang on, that seems like a different error. Do you have a netrc file at all?

[IrateNinja]

When no .netrc file is present, the throws the <SystemCallError: Unknown error - Unknown Error (0) - /home/xxx/.netrc> exception. When a .netrc file is created at that location, it freaks out about the permissions regardless of the actual permissions. I can only guess that whatever is failing to return proper results for the file stats check if also giving bad results for the permissions check.

Anything I can do to help track this down please let me know. I've left the box running to experiment with.

[lvh]

My apologies, I mixed you up with @lucashenning. @lucashenning seems to just have the "no file here" problem.

1. What does it do with both forms of native extension off? (Other than "not work" -- I appreciate that you may need extensions for the rest of your app)
2. Can you reproduce with a simple Ruby script? Looks like there's nothing special about that bit of code.

Assuming (1) and (2), that would make it a clear jruby bug. Unfortunately File::stat appears to have been fraught with peril :/

[lucashenning]

Sorry, I didn't want to confuse you with my exception. However, I think the problem is exactly the same.

1. When there is no .netrc file present on the system, I get the "SystemCallError: Unknown error - Unknown Error (0)" exception which I have mentioned before. The error is pretty much the same as @gdcbyers second exception.
2. When I create a .netrc file with 0600 permissions I get the following exception which looks also pretty identical...

Exception in filterworker {"exception"=>#<Netrc::Error: Permission bits for '/home/xxx/.netrc' should be 0600, but are 644>, "backtrace"=>[
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:45:in `check_permissions'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb:52:in `read'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:284:in `parse_url_with_auth'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:175:in `execute'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/request.rb:41:in `execute'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/rest-client-1.8.0/lib/restclient/resource.rb:54:in `get'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-rest-0.1.0/lib/logstash/filters/rest.rb:50:in `filter'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/filters/base.rb:162:in `multi_filter'", 
    "org/jruby/RubyArray.java:1613:in `each'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/filters/base.rb:159:in `multi_filter'", 
    "(eval):41:in `filter_func'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:219:in `filterworker'", 
    "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:156:in `start_filters'"
], :level=>:error}

The strange thing is that the plugin works fine on my development machine but crashes as soon as I run it on a fresh logstash installation. On the fresh system I have no .jrubyrc file laying around and the jruby properties are the same as on my dev machine. Neither native.enabled=true nor cext.enabled=false is set to another value than default on both systems. As @lvh suggested, I tried to set both values to false, but wasn't able to start Logstash then.

[lvh]

Sorry, then I'm out of ideas :( Judging by the amount of JRuby bugs related to stat and looking at the code in the netrc module, I think this is a JRuby bug?

[bigwhoop]

Can confirm exactly the same problem @gdcbyers has reported.

netrc-0.10.3

$ /opt/logstash/bin/logstash --version
logstash 1.5.2

$ java -version
java version "1.8.0_45"
Java(TM) SE Runtime Environment (build 1.8.0_45-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode)

[bigwhoop]

Here's a super ugly, hacky "solution": Change the netrc code to ignore the .netrc file ...

$ sudo nano /opt/logstash/vendor/bundle/jruby/1.9/gems/netrc-0.10.3/lib/netrc.rb
...
def self.read(path=default_path)
  return new(path, parse(lex([])))
end
...

Absolutely no guarantee that this won't break anything. But as I'm not using .netrc files anywhere on my system everything seems to work fine so far.

[lucashenning]

I can confirm that @bigwhoop's workaround works perfectly as long as you don't need netrc anywhere else.

@bigwhoop, can you make sense of this behaviour? So, guess this is a bug in netrc?