logstash-plugins / logstash-filter-jdbc_static

Loads a DB query's result set in memory and uses it as lookup table for events.
Apache License 2.0
11 stars 12 forks source link

Java::oracle.jdbc.driver.OracleDriver initialization #39

Open hadzimura opened 6 years ago

hadzimura commented 6 years ago

Hello there.

I observed series of unfortunate events today and want to share them with you as I think they are worth a notion. I'm using jdbc_static for colouring my input data in Logstash along with other implementations of JDBC used by different plugins, namely logstash-filter-jdbc_streaming and logstash-output-jdbc. Target databases are mainly Oracle and some MariaDB instancies which is irrelevant I believe but there you are.

I did some changes to my Logstash configuration here and there and suddenly out of the blue I ended up with jdbc_static throwing me this:

:error=>"Java::JavaLang::IllegalAccessError: tried to access class oracle.jdbc.driver.T4CTTIkvarr from class oracle.jdbc.driver.T4CTTIfun"

Please note that this really was no fun for me because of what the heck did I done wrong? Haven't even touched the jdbc_static config for days. I started to suspect the ojdbc6.jar driver from some deeply psychological reasons and ended up in a vicious circle of upgrading the driver file, experimenting with connection string into the database and so on. The sun slowly started to recede and the air was full of birds chirping, the midsummer night's dream was about to begin.

Then it struck me and I moved the jdbc_static initialisation at the very beginning of the configuration of Logstash pipeline. You can probably guess what happened next.

I don't know if this is somehow specific to my working enviroment but as I see it there is some kind of weird race condition (I really don't know what this term means but it seems appropriate somehow) when the drivers compete for something somewhere. And when the jdbc_static IS the king of the ball and has the priviledge of kissing the ojdbc.jar driver first, everything is just fine. Otherwise it's like in that congrevian saying:

Hell hath no fury like a jdbc_static scorned.

Writing this helepd me dealing with the pain greatly, thank you for your understanding.

hadzimura commented 6 years ago

Just for a reference: the config part of the plugin is pretty default.

loader_schedule => "0 * * * *"
staging_directory => "/opt/logstash/jdbc_static/import_data"
jdbc_user => "john"
jdbc_password => "doe"
jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
jdbc_driver_library => "/opt/logstash/ojdbc8-18c.jar"
jdbc_connection_string => "jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=1.1.1.1)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=TROLOLOL)))"
hadzimura commented 6 years ago

Current logstash behaviour:

[2018-08-20T16:59:39,068][INFO ][logstash.pipeline        ] Starting pipeline {:pipeline_id=>"default_pipeline", "pipeline.workers"=>8, "pipeline.batch.size"=>500, "pipeline.batch.delay"=>50}
[2018-08-20T16:59:39,069][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T16:59:39,070][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-13 - Starting...
[2018-08-20T16:59:39,094][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-13 - Start completed.
[2018-08-20T16:59:39,100][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T16:59:39,103][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-14 - Starting...
[2018-08-20T16:59:39,161][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-14 - Start completed.
[2018-08-20T16:59:39,164][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T16:59:39,165][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-15 - Starting...
[2018-08-20T16:59:39,218][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-15 - Start completed.
[2018-08-20T16:59:39,220][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T16:59:39,221][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-16 - Starting...
[2018-08-20T16:59:39,266][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-16 - Start completed.
[2018-08-20T16:59:39,268][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T16:59:39,268][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-17 - Starting...
[2018-08-20T16:59:39,309][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-17 - Start completed.
[2018-08-20T16:59:39,316][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T16:59:39,316][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-18 - Starting...
[2018-08-20T16:59:39,360][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-18 - Start completed.
[2018-08-20T16:59:39,365][INFO ][logstash.filters.jdbcstatic] derby.system.home is: /opt/logstash
[2018-08-20T16:59:46,348][INFO ][logstash.filters.jdbc.readwritedatabase] loader cellConfigDB, fetched 67165 records in: 6.795 seconds
[2018-08-20T16:59:47,074][INFO ][logstash.filters.jdbc.readwritedatabase] loader cellConfigDB, saved fetched records to import file in: 0.726 seconds
[2018-08-20T16:59:47,486][INFO ][logstash.filters.jdbc.readwritedatabase] loader cellConfigDB, imported all fetched records in: 0.411 seconds
[2018-08-20T16:59:47,552][INFO ][logstash.filters.jdbc.readwritedatabase] loader ggsnIpMapDB, fetched 23 records in: 0.066 seconds
[2018-08-20T16:59:47,554][INFO ][logstash.filters.jdbc.readwritedatabase] loader ggsnIpMapDB, saved fetched records to import file in: 0.001 seconds
[2018-08-20T16:59:47,569][INFO ][logstash.filters.jdbc.readwritedatabase] loader ggsnIpMapDB, imported all fetched records in: 0.016 seconds
[2018-08-20T16:59:47,570][INFO ][logstash.filters.jdbcstatic] Scheduler operations: Scheduled for: these minutes in the hour [0];these seconds in the minute [0]
[2018-08-20T16:59:47,570][INFO ][logstash.filters.jdbcstatic] Scheduler scan for work frequency is: 2.5
[2018-08-20T16:59:47,973][INFO ][logstash.inputs.beats    ] Beats inputs: Starting input listener {:address=>"0.0.0.0:5044"}
[2018-08-20T16:59:47,975][INFO ][org.logstash.beats.Server] Starting server on port: 5044
[2018-08-20T16:59:47,993][INFO ][logstash.pipeline        ] Pipeline started successfully {:pipeline_id=>"default_pipeline", :thread=>"#<Thread:0x1bd6666f@/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:245 sleep>"}
hadzimura commented 6 years ago

Previous logstash behaviour:

[2018-08-20T15:37:22,470][INFO ][logstash.pipeline        ] Starting pipeline {:pipeline_id=>"default_pipeline", "pipeline.workers"=>8, "pipeline.batch.size"=>500, "pipeline.batch.delay"=>50}
[2018-08-20T15:37:22,482][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T15:37:22,508][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-1 - Starting...
[2018-08-20T15:37:22,795][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-1 - Start completed.
[2018-08-20T15:37:22,802][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T15:37:22,802][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-2 - Starting...
[2018-08-20T15:37:22,839][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-2 - Start completed.
[2018-08-20T15:37:22,840][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T15:37:22,841][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-3 - Starting...
[2018-08-20T15:37:22,884][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-3 - Start completed.
[2018-08-20T15:37:22,885][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T15:37:22,886][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-4 - Starting...
[2018-08-20T15:37:22,924][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-4 - Start completed.
[2018-08-20T15:37:22,942][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T15:37:22,946][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-5 - Starting...
[2018-08-20T15:37:23,257][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-5 - Start completed.
[2018-08-20T15:37:23,264][INFO ][logstash.outputs.jdbc    ] JDBC - Starting up
[2018-08-20T15:37:23,265][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-6 - Starting...
[2018-08-20T15:37:23,302][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-6 - Start completed.
[2018-08-20T15:37:23,721][INFO ][logstash.filters.jdbcstatic] derby.system.home is: /opt/logstash
[2018-08-20T15:37:23,857][ERROR][logstash.pipeline        ] Error registering plugin {:pipeline_id=>"default_pipeline", :plugin=>"#<LogStash::FilterDelegator:0x64c59a98 @metric_events_out=org.jruby.proxy.org.logstash.instrument.metrics.counter.LongCounter$Proxy2 -  name: out value:0, @metric_events_in=org.jruby.proxy.org.logstash.instrument.metrics.counter.LongCounter$Proxy2 -  name: in value:0, @metric_events_time=org.jruby.proxy.org.logstash.instrument.metrics.counter.LongCounter$Proxy2 -  name: duration_in_millis value:0, @id=\"3c24c20c760e79c6408b86ca3e45d037412a3ee65df110145fe0ed462970930b\", @klass=LogStash::Filters::JdbcStatic, @metric_events=#<LogStash::Instrument::NamespacedMetric:0x1a1b38c2 @metric=#<LogStash::Instrument::Metric:0x4d0da1a1 @collector=#<LogStash::Instrument::Collector:0x5ba7fb12 @agent=nil, @metric_store=#<LogStash::Instrument::MetricStore:0x137ebba4 @store=#<Concurrent::Map:0x00000000001018 entries=3 default_proc=nil>, @structured_lookup_mutex=#<Mutex:0x50e05c21>, @fast_lookup=#<Concurrent::Map:0x0000000000101c entries=526 default_proc=nil>>>>, @namespace_name=[:stats, :pipelines, :default_pipeline, :plugins, :filters, :\"3c24c20c760e79c6408b86ca3e45d037412a3ee65df110145fe0ed462970930b\", :events]>, @filter=<LogStash::Filters::JdbcStatic loaders=>[{\"id\"=>\"cellConfigDB\", \"query\"=>\"<select statement omitted>", \"local_table\"=>\"cellConfig\", \"jdbc_driver_library\"=>\"/opt/logstash/ojdbc6-12c.jar\", \"jdbc_driver_class\"=>\"Java::oracle.jdbc.driver.OracleDriver\", \"jdbc_connection_string\"=>\"jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=1.1.1.1)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=TROLOLOL)))\", \"jdbc_user\"=>\"john\", \"jdbc_password\"=><password>, \"staging_directory\"=>\"/opt/logstash/jdbc_static/import_data\"}, {\"id\"=>\"ggsnIpMapDB\", \"query\"=>\"select statement omitted>", \"local_table\"=>\"ggsnIpMap\"}], local_db_objects=>[{\"name\"=>\"cellConfig\", \"index_columns\"=>[\"name\"], \"columns\"=>[[\"name\", \"varchar(16)\"], [\"lat\", \"float\"], [\"lon\", \"float\"], [\"tech\", \"varchar(4)\"], [\"lsite\", \"varchar(16)\"]]}, {\"name\"=>\"ggsnIpMap\", \"index_columns\"=>[\"ip_addr\"], \"columns\"=>[[\"ip_addr\", \"varchar(16)\"], [\"ggsn\", \"varchar(16)\"]]}], local_lookups=>[{\"id\"=>\"local-cellConfig\", \"query\"=>\"select statement omitted>", \"parameters\"=>{\"cellName\"=>\"[locationCell]\"}, \"target\"=>\"cellAttributes\", \"default_hash\"=>{\"tech\"=>\"Unknown\", \"lat\"=>48.8333536, \"lon\"=>12.96205, \"lsite\"=>\"Unknown\"}}, {\"id\"=>\"local-ggsnIpMap\", \"query\"=>\"select statement omitted>", \"parameters\"=>{\"ggsnIpAddr\"=>\"[GGSN_IP]\"}, \"target\"=>\"ggsnInfo\", \"default_hash\"=>{\"ggsn\"=>\"Unknown\"}}], add_field=>{\"rat\"=>\"%{[cellAttributes][0][tech]}\", \"latitude\"=>\"%{[cellAttributes][0][lat]}\", \"longitude\"=>\"%{[cellAttributes][0][lon]}\", \"locationSite\"=>\"%{[cellAttributes][0][lsite]}\", \"ggsnName\"=>\"%{[ggsnInfo][0][ggsn]}\"}, remove_field=>[\"cellAttributes\", \"ggsnInfo\"], loader_schedule=>\"0 * * * *\", staging_directory=>\"/opt/logstash/jdbc_static/import_data\", jdbc_user=>\"john\", jdbc_password=><password>, jdbc_driver_class=>\"Java::oracle.jdbc.driver.OracleDriver\", jdbc_driver_library=>\"/opt/logstash/ojdbc6-12c.jar\", jdbc_connection_string=>\"jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=1.1.1.1)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=TROLOLOL)))\", tag_on_failure=>[\"databaseFailure\"], id=>\"3c24c20c760e79c6408b86ca3e45d037412a3ee65df110145fe0ed462970930b\", enable_metric=>true, periodic_flush=>false, tag_on_default_use=>[\"_jdbcstaticdefaultsused\"]>>", :error=>"Java::JavaLang::IllegalAccessError: tried to access class oracle.jdbc.driver.T4CTTIkvarr from class oracle.jdbc.driver.T4CTTIfun", :thread=>"#<Thread:0x145bf544@/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:245 run>"}
[2018-08-20T15:37:24,111][ERROR][logstash.pipeline        ] Pipeline aborted due to error {:pipeline_id=>"default_pipeline", :exception=>#<LogStash::Filters::Jdbc::ConnectionJdbcException: Java::JavaLang::IllegalAccessError: tried to access class oracle.jdbc.driver.T4CTTIkvarr from class oracle.jdbc.driver.T4CTTIfun>, :backtrace=>["oracle.jdbc.driver.T4CTTIfun.readSPF(oracle/jdbc/driver/T4CTTIfun.java:963)", "oracle.jdbc.driver.T4CTTIfun.receive(oracle/jdbc/driver/T4CTTIfun.java:573)", "oracle.jdbc.driver.T4CTTIfun.doRPC(oracle/jdbc/driver/T4CTTIfun.java:252)", "oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(oracle/jdbc/driver/T4CTTIoauthenticate.java:499)", "oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(oracle/jdbc/driver/T4CTTIoauthenticate.java:1279)", "oracle.jdbc.driver.T4CConnection.logon(oracle/jdbc/driver/T4CConnection.java:663)", "oracle.jdbc.driver.PhysicalConnection.connect(oracle/jdbc/driver/PhysicalConnection.java:688)", "oracle.jdbc.driver.T4CDriverExtension.getConnection(oracle/jdbc/driver/T4CDriverExtension.java:39)", "oracle.jdbc.driver.OracleDriver.connect(oracle/jdbc/driver/OracleDriver.java:691)", "java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:497)", "org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:468)", "org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:326)", "RUBY.connect(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/adapters/jdbc.rb:215)", "RUBY.make_new(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/connection_pool.rb:127)", "RUBY.assign_connection(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/connection_pool/threaded.rb:206)", "RUBY.acquire(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/connection_pool/threaded.rb:138)", "RUBY.hold(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/connection_pool/threaded.rb:90)", "RUBY.synchronize(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/database/connecting.rb:270)", "RUBY.test_connection(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/database/connecting.rb:279)", "RUBY.connect(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/database/connecting.rb:58)", "RUBY.connect(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/core.rb:116)", "RUBY.verify_connection(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc/basic_database.rb:108)", "RUBY.post_create(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc/read_only_database.rb:48)", "RUBY.create(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc/basic_database.rb:33)", "RUBY.build_remote_db(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc/loader.rb:18)", "RUBY.block in prepare_runner(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc_static.rb:178)", "org.jruby.RubyArray.collect(org/jruby/RubyArray.java:2472)", "org.jruby.RubyArray.map(org/jruby/RubyArray.java:2486)", "org.jruby.RubyArray$INVOKER$i$0$0$map19.call(org/jruby/RubyArray$INVOKER$i$0$0$map19.gen)", "RUBY.prepare_runner(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc_static.rb:175)", "RUBY.register(/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-filter-jdbc_static-1.0.5/lib/logstash/filters/jdbc_static.rb:146)", "org.jruby.RubyClass.finvoke(org/jruby/RubyClass.java:522)", "org.jruby.RubyBasicObject.send19(org/jruby/RubyBasicObject.java:1684)", "org.jruby.RubyBasicObject$INVOKER$i$send19.call(org/jruby/RubyBasicObject$INVOKER$i$send19.gen)", "usr.share.logstash.logstash_minus_core.lib.logstash.pipeline.invokeOther0:register(usr/share/logstash/logstash_minus_core/lib/logstash//usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:340)", "usr.share.logstash.logstash_minus_core.lib.logstash.pipeline.register_plugin(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:340)", "usr.share.logstash.logstash_minus_core.lib.logstash.pipeline.invokeOther0:register_plugin(usr/share/logstash/logstash_minus_core/lib/logstash//usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:351)", "usr.share.logstash.logstash_minus_core.lib.logstash.pipeline.block in register_plugins(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:351)", "org.jruby.RubyArray.each(org/jruby/RubyArray.java:1734)", "org.jruby.RubyArray$INVOKER$i$0$0$each.call(org/jruby/RubyArray$INVOKER$i$0$0$each.gen)", "RUBY.register_plugins(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:351)", "RUBY.maybe_setup_out_plugins(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:729)", "RUBY.start_workers(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:361)", "RUBY.run(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:288)", "RUBY.block in start(/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:248)", "org.jruby.RubyProc.call(org/jruby/RubyProc.java:289)", "org.jruby.RubyProc.call(org/jruby/RubyProc.java:246)", "java.lang.Thread.run(java/lang/Thread.java:745)"], :thread=>"#<Thread:0x145bf544@/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:245 run>"}
[2018-08-20T15:37:24,116][ERROR][logstash.agent           ] Failed to execute action {:id=>:default_pipeline, :action_type=>LogStash::ConvergeResult::FailedAction, :message=>"Could not execute action: PipelineAction::Create<default_pipeline>, action_result: false", :backtrace=>nil}
guyboertje commented 6 years ago

@hadzimura

[2018-08-20T16:59:39,070][INFO ][com.zaxxer.hikari.HikariDataSource] HikariPool-13 - Starting...

This line tells me that you, somehow, are using code that has not been released yet. The Hikari Connection Pool code is still in a pull request.

Did you build a custom plugin from the PR?

Jar class loading is and has been a real issue for Logstash JDBC plugins. The error you see is an access violation where classes loaded via one class loader are interacting with classes loaded via another class loader.

The PR changes the manner in which the Derby driver jars for jdbc_static are loaded only the remote database drivers should still be loaded in the same way as before - indeed the access error is thrown by the 3rd party code that handles the remote side. logstash/vendor/bundle/jruby/2.3.0/gems/sequel-5.11.0/lib/sequel/adapters/jdbc.rb It would be great if you can share your redacted config so I can try to recreate this problem.

hadzimura commented 6 years ago

Hi, no no no these are the other plugins Hikari Pools, thats the reason i mentioned that I use other JDBC filters/inputs/outputs as well. My jdbc_static plugin is pretty standard 1.0.5 version right out of the

logstash-plugins install logstash-filter-jdbc_static

... no monkey business involved. I can share some of the logstash-output-jdbc snippet if that helps (and try to test if it causes the crash beforehand of course).

The rest of the explanation sounds pretty sound to me, I was explaining it to myself in a errr, almost similar way.

One more thing, I didn't thanked you for fixing the Derby loader so thank you very much: the strange thing is that I was using the jdbc_streaming plugin as a workaround and actually switched back to this one AFTER the streaming one started to show exactly the same behaviour as jdbc_static. There is something rotten in the state of Logstash (warning: a metaphore usage detected).