Writing to sincedb fails on arm64 nodes

[robbavey]

Running a simple logstash file input pipeline:

input {                                                                         
  stdin {}                                                                      
  file {                                                                        
    path => "/home/ec2-user/logstash-7.10.2/logs/*.log"                                           
  }                                                                             
}   

on a newly provisioned t4g.micro AWS graviton2 equipped EC2 instance results in the following error:

[2021-01-27T15:05:43,986][ERROR][logstash.javapipeline    ][main][5f530e7945bfbf4772f27679f28f3827e86eeefe3a458ef34b4456b91fb2e21f] A plugin had an unrecoverable error. Will restart this plugin.
  Pipeline_id:main
  Plugin: <LogStash::Inputs::File path=>["/home/ec2-user/logstash-7.10.2/logs/*.log"], id=>"5f530e7945bfbf4772f27679f28f3827e86eeefe3a458ef34b4456b91fb2e21f", enable_metric=>true, codec=><LogStash::Codecs::Plain id=>"plain_9b5027d7-e749-4d12-af5c-f357f2fc3519", enable_metric=>true, charset=>"UTF-8">, stat_interval=>1.0, discover_interval=>15, sincedb_write_interval=>15.0, start_position=>"end", delimiter=>"\n", close_older=>3600.0, mode=>"tail", file_completed_action=>"delete", sincedb_clean_after=>1209600.0, file_chunk_size=>32768, file_chunk_count=>140737488355327, file_sort_by=>"last_modified", file_sort_direction=>"asc", exit_after_read=>false, check_archive_validity=>false>
  Error: Operation not permitted - No message available
  Exception: Errno::EPERM
  Stack: org/jruby/RubyFile.java:675:in `chown'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/helper.rb:41:in `write_atomically'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/sincedb_collection.rb:228:in `atomic_write'
org/jruby/RubyMethod.java:119:in `call'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/sincedb_collection.rb:212:in `sincedb_write'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/sincedb_collection.rb:185:in `flush_at_interval'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/sincedb_collection.rb:32:in `request_disk_flush'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/handlers/base.rb:78:in `controlled_read'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/handlers/grow.rb:10:in `block in handle_specifically'
org/jruby/RubyKernel.java:1442:in `loop'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/handlers/grow.rb:7:in `handle_specifically'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/handlers/base.rb:25:in `handle'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/processor.rb:43:in `grow'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/processor.rb:234:in `block in process_active'
org/jruby/RubyArray.java:1809:in `each'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/processor.rb:228:in `process_active'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/tail_mode/processor.rb:75:in `process_all_states'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/watch.rb:70:in `iterate_on_state'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/watch.rb:44:in `subscribe'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/filewatch/observing_tail.rb:12:in `subscribe'
/home/ec2-user/logstash-7.10.2/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.3/lib/logstash/inputs/file.rb:364:in `run'
/home/ec2-user/logstash-7.10.2/logstash-core/lib/logstash/java_pipeline.rb:405:in `inputworker'
/home/ec2-user/logstash-7.10.2/logstash-core/lib/logstash/java_pipeline.rb:396:in `block in start_input'

This same pipeline works correctly on a similarly newly provisioned t2.micro instance

[robbavey]

Adding related discuss issues:

https://discuss.elastic.co/t/logstash-7-9-1-have-issues-in-arm/249596
https://discuss.elastic.co/t/issue-with-logstash-on-aarch64/133008/10
https://discuss.elastic.co/t/logstash-a-plugin-had-an-unrecoverable-error-aws-arm64-ubuntu-20-04-java-openjdk-11/255146

[TheVastyDeep]

The write_atomically function calls chown, which makes no sense. It assumes the code is running as root, since only a privileged process can chown a file. Perhaps it should chgrp (and ignore a failure)?

write_atomically is not used on Windows, and otherwise is only used if sincedb_path points to something that is neither a character nor a block device. I have no idea how a filesystem could be neither a character nor a block device, but it seems to happen.

[jvedman]

My personal (and likely bad) solution to this problem is to modify the ruby file that handles this process. The file in question is:
/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-file-4.2.4/lib/filewatch/sincedb_collection.rb

On line 18 (if memory serves) you'll find this line:
@write_method = LogStash::Environment.windows? || @path.chardev? || @path.blockdev? ? method(:non_atomic_write) : method(:atomic_write)

Change that to:
@write_method = LogStash::Environment.windows? || @path.chardev? || @path.blockdev? ? method(:non_atomic_write) : method(:non_atomic_write)

and everything works fine... at least until you update Logstash...

[robbavey]

Update on this issue:

This is being caused by an upstream jruby issue where File.stat is returning incorrect results for uid, gid and nlink due to incorrect struct layout mappings in libraries used by jruby/logtash. This is resulting in 0 being returned for both uid and gid, which is resulting in the permissions error as the call to chown attempts to set ownership of the file to root, which is clearly not allowed.

I have opened issues and PR's in the repositories to attempt to fix this issue:

Issues:
jnr/jnr-posix#164
jnr/jnr-ffi#240

PRs:
jnr/jnr-posix#165
jnr/jnr-ffi#241

[TheVastyDeep]

Surely the chown is never going to work unless logstash is running as root. Regular users cannot use chown on any UNIX variant I am familiar with.

[robbavey]

@TheVastyDeep I tend to agree - chown is likely to only work if logstash is being run as root, or the chown operation is changing the group ownership of the file to a group that the user is also a member of. To that end, I've put up a PR that makes chown less prone to catastrophic failure. It will only be called in the unlikely event that the temp file needs a chown operation, and will not fail the plugin catastrophically if it actually does need to be called.

That being said... even with this PR (or even removing the chown operation altogether), given the nature of the File.stat issue, I would be wary of using this plugin in a production environment on aarch64 nodes until the underlying upstream jruby issue mentioned above is fixed.

[arnaudmm]

Hello,

What is the status of this issue since the jruby issue has been adressed?

Do you have an idea in which Logstash version the fix will be included?

Thanks a lot

[robbavey]

Hi @arnaudmm - thanks for the reminder. I'm going to close this issue as it should have been addressed, both by the PR I mentioned earlier, and by the upstream jruby fixes.

The latest version of Logstash (7.14.0 at time of writing) should have the necessary fixes for this to work. If you still have issues, please feel free to add a new issue, or reopen this one with details.