Error writing to last_run_metadata_path with Logstash 7.12.1+
boutetnico opened this issue · 3 comments
boutetnico commented
Logstash information:
bin/logstash --version
Using bundled JDK: /usr/share/logstash/jdk
logstash 7.12.1
-
Installation source: deb
-
Run through systemd
-
Plugin installed with ansible
logstash_pluginmodule
JVM (e.g. java -version):
java -version
openjdk version "11.0.6" 2020-01-14
OpenJDK Runtime Environment (build 11.0.6+10-post-Debian-1bpo91)
OpenJDK 64-Bit Server VM (build 11.0.6+10-post-Debian-1bpo91, mixed mode, sharing)
OS version (uname -a if on a Unix-like system):
Linux vm01 4.9.0-6-amd64 #1 SMP Debian 4.9.88-1+deb9u1 (2018-05-07) x86_64 GNU/Linux
Description of the problem including expected versus actual behaviour:
Since upgrade to Logstash 7.12.1, logstash jdbc plugin is not able anymore to write to /usr/share/logstash/.logstash_jdbc_last_run.
I suspect it's due to elastic/logstash#12782 which changed ownership of /usr/share/logstash from logstash:logstash to root:root.
Steps to reproduce:
-Create a jdbc input
input {
jdbc {
add_field => {
type => "mysql_message"
}
jdbc_driver_library => ""
jdbc_driver_class => "org.mariadb.jdbc.Driver"
jdbc_connection_string => "jdbc:mariadb://localhost:3306/mydb"
jdbc_user => "logstash"
jdbc_password => "logstash"
jdbc_fetch_size => 1000
schedule => "* * * * *"
statement => "SELECT * from table WHERE id > :sql_last_value"
use_column_value => true
tracking_column => "id"
}
}
- Open syslog and notice the error below
Provide logs (if relevant):
Apr 30 08:12:00 vm01 logstash[24905]: { 2122 rufus-scheduler intercepted an error:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 job:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 Rufus::Scheduler::CronJob "* * * * *" {}
Apr 30 08:12:00 vm01 logstash[24905]: 2122 error:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 2122
Apr 30 08:12:00 vm01 logstash[24905]: 2122 Errno::EACCES
Apr 30 08:12:00 vm01 logstash[24905]: 2122 Permission denied - /usr/share/logstash/.logstash_jdbc_last_run
Apr 30 08:12:00 vm01 logstash[24905]: 2122 org/jruby/RubyIO.java:1237:in `sysopen'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 org/jruby/RubyIO.java:3800:in `write'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.6/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:122:in `write'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.6/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:46:in `write'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.6/lib/logstash/inputs/jdbc.rb:325:in `execute_query'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.6/lib/logstash/inputs/jdbc.rb:279:in `block in run'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:234:in `do_call'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:258:in `do_trigger'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:300:in `block in start_work_thread'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:299:in `block in start_work_thread'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 org/jruby/RubyKernel.java:1442:in `loop'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:289:in `block in start_work_thread'
Apr 30 08:12:00 vm01 logstash[24905]: 2122 tz:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 ENV['TZ']:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 Time.now: 2021-04-30 08:12:00 +0000
Apr 30 08:12:00 vm01 logstash[24905]: 2122 scheduler:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 object_id: 2086
Apr 30 08:12:00 vm01 logstash[24905]: 2122 opts:
Apr 30 08:12:00 vm01 logstash[24905]: 2122 {:max_work_threads=>1}
Apr 30 08:12:00 vm01 logstash[24905]: 2122 frequency: 0.3
Apr 30 08:12:00 vm01 logstash[24905]: 2122 scheduler_lock: #<Rufus::Scheduler::NullLock:0x66075c4a>
Apr 30 08:12:00 vm01 logstash[24905]: 2122 trigger_lock: #<Rufus::Scheduler::NullLock:0x5cd4edb1>
Apr 30 08:12:00 vm01 logstash[24905]: 2122 uptime: 1060.8830520000001 (17m40s883)
Apr 30 08:12:00 vm01 logstash[24905]: 2122 down?: false
Apr 30 08:12:00 vm01 logstash[24905]: 2122 threads: 2
Apr 30 08:12:00 vm01 logstash[24905]: 2122 thread: #<Thread:0x34732726>
Apr 30 08:12:00 vm01 logstash[24905]: 2122 thread_key: rufus_scheduler_2086
Apr 30 08:12:00 vm01 logstash[24905]: 2122 work_threads: 1
Apr 30 08:12:00 vm01 logstash[24905]: 2122 active: 1
Apr 30 08:12:00 vm01 logstash[24905]: 2122 vacant: 0
Apr 30 08:12:00 vm01 logstash[24905]: 2122 max_work_threads: 1
Apr 30 08:12:00 vm01 logstash[24905]: 2122 mutexes: {}
Apr 30 08:12:00 vm01 logstash[24905]: 2122 jobs: 1
Apr 30 08:12:00 vm01 logstash[24905]: 2122 at_jobs: 0
Apr 30 08:12:00 vm01 logstash[24905]: 2122 in_jobs: 0
Apr 30 08:12:00 vm01 logstash[24905]: 2122 every_jobs: 0
Apr 30 08:12:00 vm01 logstash[24905]: 2122 interval_jobs: 0
Apr 30 08:12:00 vm01 logstash[24905]: 2122 cron_jobs: 1
Apr 30 08:12:00 vm01 logstash[24905]: 2122 running_jobs: 1
Apr 30 08:12:00 vm01 logstash[24905]: 2122 work_queue: 0
Apr 30 08:12:00 vm01 logstash[24905]: } 2122 .
jsvd commented
Thanks for reporting this, data files should be written to the configured path.data directory, but it seems this plugin was never updated.
Fixing this without regressing to the old permissions means we should adapt the rpm/deb package upgrade process to move the file and fix the permissions. /cc @roaksoax
predogma commented
This issue is still occurring when using YUM install in version 8.1.x logstash with logstash-integration-jdbc-5.2.4
[2022-04-19T18:37:01,471][INFO ][logstash.inputs.jdbc ][main][5a15e44582c699526aaec6991fe97443d1f18be96a905a66a7f169e706ac8e76] (0.071188s) SELECT TOP (10) * FROM [Entserve_p].[dbo].[LOG] where USER_NM like 'esteamas%p' AND LOG_ID > 0
[2022-04-19T18:37:02,007][ERROR][logstash.pluginmixins.jdbc.scheduler][main][5a15e44582c699526aaec6991fe97443d1f18be96a905a66a7f169e706ac8e76] Scheduler intercepted an error: {:exception=>Errno::EACCES,
:message=>"Permission denied - /usr/share/logstash/.logstash_jdbc_last_run", :backtrace=>["org/jruby/RubyIO.java:1237:in `sysopen'", "org/jruby/RubyIO.java:3800:in `write'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.2.4/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:119:in `write'",
...
brunobastosg commented
I recently updated from Logstash 7.9.2 to 7.17.3 and this error started to happen.
As a workaround I created a folder /home/logstash with owner logstash:logstash and set last_run_metadata_path to a file in that folder.