Logstash JDBC input plugin skips few scheduled runs

Elastic Stack Logstash
1

Hi All,
We're using JDBC input plugin to load data from Oracle 19c DB. Totally 55 separate config files ( each per client ) . Each file having 4 different sections for JDBC input, scheduled to run every 10 secs.
Some times scheduled run is not happening, after 2 mins or so, for a single client or 2. Not all the 4 sections of the jdbc input is skipped, may be one or two. Its happening for random clients. No errors in the logs. Not sure how to triage this. Request your help in identifying the issue.

Code Snippet.

input{
        jdbc{
                jdbc_driver_library => "/etc/logstash/jdbc/drivers/ojdbc7.jar"
                jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
                jdbc_validate_connection => true
		jdbc_connection_string => "jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS_LIST=(LOAD_BALANCE=OFF)(FAILOVER=ON)(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111)))(CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ELK)))"
		jdbc_user=>"USER"
                jdbc_password => "${PASS}"
                jdbc_fetch_size => 300
                jdbc_default_timezone => "EST"
                schedule => "*/10 * * * * *"
                statement_filepath => "/etc/logstash/conf.d/SQL/XXX/XXX_MESSAGES_STATEMENT.SQL"
                tracking_column => "hm_id"
                use_column_value => true
                tracking_column_type => "numeric"
                last_run_metadata_path => "/etc/logstash/conf.d/SQL/XXX/sql_last_value/XXX_MESSAGES.yml"
		type => "123"

        }

	jdbc{
                jdbc_driver_library => "/etc/logstash/jdbc/drivers/ojdbc7.jar"
                jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
                jdbc_validate_connection => true
		jdbc_connection_string => "jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS_LIST=(LOAD_BALANCE=OFF)(FAILOVER=ON)(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111)))(CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ELK)))"
		jdbc_user=>"USER"
                jdbc_password => "${PASS}"
                jdbc_fetch_size => 300
                jdbc_default_timezone => "EST"
                schedule => "*/10 * * * * *"
                statement_filepath => "/etc/logstash/conf.d/SQL/XXX/XXX_STATEMENT.SQL"
                tracking_column => "sit_id"
                use_column_value => true
                tracking_column_type => "numeric"
                last_run_metadata_path => "/etc/logstash/conf.d/SQL/XXX/sql_last_value/XXX_INOUT.yml"
		type => "123"
        }

	jdbc{
                jdbc_driver_library => "/etc/logstash/jdbc/drivers/ojdbc7.jar"
                jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
                jdbc_validate_connection => true
		jdbc_connection_string => "jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS_LIST=(LOAD_BALANCE=OFF)(FAILOVER=ON)(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111)))(CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ELK)))"
		jdbc_user=>"USER"
                jdbc_password => "${PASS}"
                jdbc_fetch_size => 300
                jdbc_default_timezone => "EST"
                schedule => "*/10 * * * * *"
                statement_filepath => "/etc/logstash/conf.d/SQL/XXX/XXX_STATEMENT.SQL"
                tracking_column => "srq_id"
                use_column_value => true
                tracking_column_type => "numeric"
                last_run_metadata_path => "/etc/logstash/conf.d/SQL/XXX/sql_last_value/XXX_.yml"
		type => "123"
        }

        jdbc{
                jdbc_driver_library => "/etc/logstash/jdbc/drivers/ojdbc7.jar"
                jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
                jdbc_validate_connection => true
		jdbc_connection_string => "jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS_LIST=(LOAD_BALANCE=OFF)(FAILOVER=ON)(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111))(ADDRESS=(PROTOCOL=TCP)(HOST=XXXXXX)(PORT=1111)))(CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=ELK)))"
		jdbc_user=>"USER"
                jdbc_password => "${PASS}"
                jdbc_fetch_size => 300
                jdbc_default_timezone => "EST"
                schedule => "*/10 * * * * *"
                statement_filepath => "/etc/logstash/conf.d/SQL/XXX/XXX_REQUEST_STATEMENT.SQL"
                tracking_column => "db_id"
                use_column_value => true
                tracking_column_type => "numeric"
                last_run_metadata_path => "/etc/logstash/conf.d/SQL/XXX/sql_last_value/XXX_REQUEST.yml"
		type => "123"
        }

}
2

Adding more context here. Enabled Increased debug log for jdbc to trace.
Observed a dip in Kibana for one client. As per Kibana last data was on 12:12:24 and after that data started at 12:14:27. When I checked the logs for the SQL run occurrences I see there was a run for this client at 12:12:20, 12:12:30, then no runs for ~2mins then as per log SQL run at 12:14:47. There are no exceptions, not sure why there were no scheduled runs for almost 2 mins.

3

Hi All,

Kindly provide your inputs to approach this issue and fix it.

Thank you

4

Since your configuration runs every 10 seconds, it might be too frequent for some queries to complete. Is it possible to test by temporary increasing the interval value until a stabilization point is found to isolate the causes?

It might be necessary to split the file into separate Logstash instances, among other solutions

5

Thank you for your response. We are running single instance of Single instance of all ELK stack. Checked with DBA team all the queries fired from Logstash are completing in milliseconds or max by 5-6 seconds (rarely). So worker threads should be available I believe so the next 10 seconds shouldn't stop (Its my own understanding).
Our server running on RedHat 7.9 with 6 core CPU and 15 GB RAM. ELLK stack version is 7.17.6 .

There are 55 DB interacting config files multiplied by 4 times, there are 220 queries configured to run every 10 sec.

It was working fine, but lately something disturbed the environment, don't which one, and since no logs are logging couldn't figure out the issue.

Log showing scheduler skipped random queries

[2024-07-12T12:12:10,270][INFO ][logstash.inputs.jdbc     ][main][d90096384d0dff6b0d991abdf7bca564c84f3b1218c97d2aa6f12186ce88d556] (0.058120s) SELECT

[2024-07-12T12:12:20,416][INFO ][logstash.inputs.jdbc     ][main][d90096384d0dff6b0d991abdf7bca564c84f3b1218c97d2aa6f12186ce88d556] (0.089003s) SELECT

[2024-07-12T12:12:30,403][INFO ][logstash.inputs.jdbc     ][main][d90096384d0dff6b0d991abdf7bca564c84f3b1218c97d2aa6f12186ce88d556] (0.082192s) SELECT

[2024-07-12T12:14:47,572][INFO ][logstash.inputs.jdbc     ][main][d90096384d0dff6b0d991abdf7bca564c84f3b1218c97d2aa6f12186ce88d556] (0.094535s) SELECT

Checked randomly on the query execution time from the logs mostly I could see in the range of 0.00....s or 0.0....s only.

Could you please guide me in triage step I can take to see what is going on behind the scene.

6

Any specific logger that needs to be increased to capture the logs to see why the scheduled runs had skipped ~2 mins? Please let me know.

7

Just noticed a bug raised to same issue. crond job successful execute a few times, but stuck without any error log later · Issue #88 · logstash-plugins/logstash-integration-jdbc · GitHub I believe this is the same.