logstash-plugins / logstash-output-file

Apache License 2.0
23 stars 53 forks source link

Unable to write to file after it is set to append only and closed/opened #51

Closed erikanderson closed 3 years ago

erikanderson commented 7 years ago

We are testing the ability for logstash to write to an append only file for security purposes. (Ubuntu 14.04/Logstash 5.2.2)

We let logstash create and open the file, then set the target file to append only, using chattr +a {file}.

Logstash is able to continue writing to the file but once it closes and then attempts to open the file again logstash produces this error and crashes: https://gist.github.com/erikanderson/fd243942d7119bb116baec2318ff6b6e

[2017-03-13T14:34:24,744][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<Errno::EACCES: Permission denied - /var/local/logstash/****-2017.03.13>, :backtrace=>["org/jruby/RubyFile.java:370:in `initialize'", "org/jruby/RubyIO.java:871:in `new'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/logstash-output-file-4.0.1/lib/logstash/outputs/file.rb:280:in `open'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/logstash-output-file-4.0.1/lib/logstash/outputs/file.rb:132:in `multi_receive_encoded'", "org/jruby/RubyHash.java:1342:in `each'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/logstash-output-file-4.0.1/lib/logstash/outputs/file.rb:131:in `multi_receive_encoded'", "org/jruby/ext/thread/Mutex.java:149:in `synchronize'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/logstash-output-file-4.0.1/lib/logstash/outputs/file.rb:130:in `multi_receive_encoded'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/outputs/base.rb:90:in `multi_receive'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/output_delegator_strategies/shared.rb:12:in `multi_receive'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/output_delegator.rb:43:in `multi_receive'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/pipeline.rb:414:in `output_batch'", "org/jruby/RubyHash.java:1342:in `each'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/pipeline.rb:413:in `output_batch'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/pipeline.rb:371:in `worker_loop'", "/srv/logstash/logstash-5.2.2/logstash-core/lib/logstash/pipeline.rb:331:in `start_workers'"]}
[2017-03-13T14:34:24,756][DEBUG][logstash.agent           ] Error in reactor loop escaped: Bad file descriptor - Bad file descriptor (Errno::EBADF)
[2017-03-13T14:34:24,757][DEBUG][logstash.agent           ] ["org/jruby/RubyIO.java:3705:in `select'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/puma-2.16.0-java/lib/puma/reactor.rb:29:in `run_internal'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/puma-2.16.0-java/lib/puma/reactor.rb:138:in `run_in_thread'"]
[2017-03-13T14:34:24,757][DEBUG][logstash.agent           ] 2017-03-13 14:34:24 -0600: Listen loop error: #<Errno::EBADF: Bad file descriptor - Bad file descriptor>
[2017-03-13T14:34:24,757][DEBUG][logstash.agent           ] org/jruby/RubyIO.java:3705:in `select'
/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/puma-2.16.0-java/lib/puma/server.rb:322:in `handle_servers'
/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/puma-2.16.0-java/lib/puma/server.rb:296:in `run'
[2017-03-13T14:34:24,757][DEBUG][logstash.agent           ] Error in reactor loop escaped: Bad file descriptor - Bad file descriptor (Errno::EBADF)
[2017-03-13T14:34:24,757][DEBUG][logstash.agent           ] ["org/jruby/RubyIO.java:3705:in `select'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/puma-2.16.0-java/lib/puma/reactor.rb:29:in `run_internal'", "/srv/logstash/logstash-5.2.2/vendor/bundle/jruby/1.9/gems/puma-2.16.0-java/lib/puma/reactor.rb:138:in `run_in_thread'"]

I realize this is probably an issue within ruby/jruby and I am going to research if there is a way to accomodate this.

jordansissel commented 7 years ago

The error is this: Errno::EACCES: Permission denied

The first logstash code line in the stack trace is this: .../gems/logstash-output-file-4.0.1/lib/logstash/outputs/file.rb:280:in `open'"

Line 280 of file.rb is this:

 fd = File.new(path, "a+")

So, we are opening the file in "append" mode, at least, as far as the Ruby code we are calling. Honestly, I have no knowledge of what chattr +a causes on a file in terms of what syscalls will fail, so I'll need your help debugging this. strace output and other testing would help.

jordansissel commented 7 years ago

Looks like JRuby 's append opens the file like this:

open("/home/jls/a", O_RDWR|O_CREAT, 0666) = -1 EPERM (Operation not permitted)

And MRI does this:

open("a", O_RDWR|O_CREAT|O_APPEND|O_CLOEXEC, 0666) = 7

The lack of O_APPEND seems to be the problem, and this isn't something (I don't think?) Logstash can fix. This could be somewhere upstream in JRuby or Java.

jordansissel commented 7 years ago

I am guessing this is an unfortunate integration problem between Linux's specific chattr +a behavior and JRuby's implementation of opening-files-for-append (at least in JRuby 1.7.26, it seems). I haven't dug any deeper.

On Mon, Mar 13, 2017 at 4:38 PM, Jordan Sissel notifications@github.com wrote:

Looks like JRuby 's append opens the file like this:

open("/home/jls/a", O_RDWR|O_CREAT, 0666) = -1 EPERM (Operation not permitted)

And MRI does this:

open("a", O_RDWR|O_CREAT|O_APPEND|O_CLOEXEC, 0666) = 7

The lack of O_APPEND seems to be the problem, and this isn't something (I don't think?) Logstash can fix. This could be somewhere upstream in JRuby or Java.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/logstash-plugins/logstash-output-file/issues/51#issuecomment-286277246, or mute the thread https://github.com/notifications/unsubscribe-auth/AAIC6rih4waQW7m65pPtxwfqvMHs6ETUks5rldNhgaJpZM4MbyKG .

jordansissel commented 7 years ago

Java does the right thing with FileOutputStream if true is given for the append argument, new FileOutputStream("some path", true) and this mode in Java works against chattr +a files in my testing.

erikanderson commented 7 years ago

Thanks for the research you've done so far.

It looks like jruby should be understanding the 'a' and the '+' flags correctly so I'm not sure where the disconnect is, going to look into it

https://github.com/jruby/jruby/blob/a4f964bb3903825f2e65b608f1120f687d6fcd97/core/src/main/java/org/jruby/util/io/ModeFlags.java#L122

erikanderson commented 7 years ago

I tried fd = File.new(path, "a+") with jruby 9.1.7.0 and didn't get the Errno::EACCES: Permission denied error

jruby-9.1.7.0 :001 > fd = File.new('test', 'a+')
 => #<File:test>
jruby-9.1.7.0 :002 > fd.write('asd')
 => 3

Same test fails with jruby 1.7.22

jruby-1.7.22 :001 > fd = File.new('test', 'a+')
Errno::EACCES: Permission denied - /home/erik.anderson/test
    from org/jruby/RubyFile.java:364:in `initialize'
    from org/jruby/RubyIO.java:853:in `new'
    from (irb):1:in `evaluate'
    from org/jruby/RubyKernel.java:1079:in `eval'
    from org/jruby/RubyKernel.java:1479:in `loop'
    from org/jruby/RubyKernel.java:1242:in `catch'
    from org/jruby/RubyKernel.java:1242:in `catch'
    from /usr/local/rvm/rubies/jruby-1.7.22/bin/irb:13:in `(root)'