Psych::DisallowedClass exception: Tried to load unspecified class: DateTime

[jbwl]

Logstash information:

Please include the following information:

1. Logstash version: 8.7.1 (also tested on 8.8.0, 8.8.1)
2. Logstash installation source: https://artifacts.elastic.co/packages/8.x/apt stable main
3. How is Logstash being run: Systemd / Ubuntu 22.04
4. How was the Logstash Plugin installed: sudo logstash-plugin install

JVM (e.g. java -version): openjdk 11.0.19 2023-04-18

OS version (uname -a if on a Unix-like system): Linux b2b 5.15.0-73-generic #80-Ubuntu SMP Mon May 15 15:18:26 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Description of the problem including expected versus actual behavior:
Pipeline using the JDBC input from this plugin will terminate with the exception mentioned in the topic.

Steps to reproduce:

• Create a logstash config using a jdbc input.
• Run this config in a logstash pipeline

Please include a minimal but complete recreation of the problem,
including (e.g.) pipeline definition(s), settings, locale, etc. The easier
you make for us to reproduce it, the more likely that somebody will take the
time to look at it.

Pipeline definition:

input {
    jdbc {
        last_run_metadata_path => "<PATH>"
        jdbc_driver_library => "/var/pipeline/current/db/clickhouse-jdbc-0.3.2-patch11-all.jar"
        jdbc_driver_class => "com.clickhouse.jdbc.ClickHouseDriver"
        jdbc_connection_string => "jdbc:ch:http://127.0.0.1:8123/"
        jdbc_user => "x"
        jdbc_password => "y"
        jdbc_default_timezone => "UTC"
        jdbc_validate_connection => true
        schedule => "35 5,8,11,13,17,23 * * * Europe/Berlin"
        record_last_run => "true"
        use_column_value => "true"
        tracking_column => "_insert_timestamp"
        tracking_column_type => "timestamp"
        statement => "SELECT a,b,c FROM table PREWHERE _insert_timestamp > toDateTime(replaceRegexpOne(:sql_last_value,'\\..*', ''))"
    }
}

2. locale: en-US

Provide logs (if relevant):

[2023-06-13T12:30:15,379][ERROR][logstash.javapipeline    ][ch2es] Pipeline error {:pipeline_id=>"ch2es", :exception=>#<Psych::DisallowedClass: Tried to load unspecified class: DateTime>, :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/class_loader.rb:99:in `find'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/class_loader.rb:28:in `load'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/class_loader.rb:40:in `date_time'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:81:in `deserialize'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:130:in `visit_Psych_Nodes_Scalar'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/visitor.rb:30:in `visit'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/visitor.rb:6:in `accept'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:35:in `accept'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:320:in `visit_Psych_Nodes_Document'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/visitor.rb:30:in `visit'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/visitor.rb:6:in `accept'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:35:in `accept'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych.rb:334:in `safe_load'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych.rb:369:in `load'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:115:in `read'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:48:in `common_set_initial'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:73:in `set_initial'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:31:in `initialize'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:22:in `build_last_value_tracker'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/inputs/jdbc.rb:285:in `register'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-mixin-ecs_compatibility_support-1.3.0-java/lib/logstash/plugin_mixins/ecs_compatibility_support/target_check.rb:48:in `register'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:237:in `block in register_plugins'", "org/jruby/RubyArray.java:1865:in `each'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:236:in `register_plugins'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:395:in `start_inputs'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:320:in `start_workers'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:194:in `run'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:146:in `block in start'"], "pipeline.sources"=>["/var/pipeline/current/config/logstash_service/ch2es/production/ch2es_production_logstash.conf"], :thread=>"#<Thread:0x496a22d0 run>"}
[2023-06-13T12:30:15,379][INFO ][logstash.javapipeline    ][ch2es] Pipeline terminated {"pipeline.id"=>"ch2es"}
[2023-06-13T12:30:15,387][ERROR][logstash.agent           ] Failed to execute action {:id=>:ch2es, :action_type=>LogStash::ConvergeResult::FailedAction, :message=>"Could not execute action: PipelineAction::Create<ch2es>, action_result: false", :backtrace=>nil}

[consulthys]

It looks like this is happening when the jdbc input plugin tries to load its last run state from a file and deserializes the timestamp (using the the Time class in the Psych YAML parser).

Deleting the .logstash_jdbc_last_run (or the one you specified) solves the issue, but you lose your state and restart from the beginning

[consulthys]

Looking further, it might be due to this change: #106
The documentation wasn't updated: #135
If you move your .logstash_jdbc_last_run to the data.path folder, it might solve the problem.

[jbwl]

Looking further, it might be due to this change: #106 The documentation wasn't updated: #135 If you move your .logstash_jdbc_last_run to the data.path folder, it might solve the problem.

Thank you for this idea. I will give it a try, but am sceptical because I am always using absolute paths for the .logstash_jdbc_last_run file, and this path is writeable for the logstash process. I will report back.

[jbwl]

It looks like this is happening when the jdbc input plugin tries to load its last run state from a file and deserializes the timestamp (using the the Time class in the Psych YAML parser).

Deleting the .logstash_jdbc_last_run (or the one you specified) solves the issue, but you lose your state and restart from the beginning

I can confirm that deleting the last_run file makes the exception disappear, the config runs without an error, and a new last_run file is written to the absolute path. Then, for testing, using the previous file will make throw the exception again.

I examined the working last_run file and the non-working one with lsattr - they are the exact same attributes. Also the ownership is the same.

[jbwl]

This exception was caused by an accidental install of the Psych 5.x gem in Logstash's jruby bundle. This led to incompatible YAML methods overriding the Logstash core supplied ones. Sorry for the confusion.

[consulthys]

Good find @jbwl
You should reopen it then

[jbwl]

It was a User / DevOp mistake, not a bug in Logstash or this plugin.

[lukasertl]

This is still broken, but I don't see how I as user am at fault.

8.8.0 - fine
8.8.1 - broken

[2023-06-16T10:27:26,269][ERROR][logstash.javapipeline    ][oracleaudit] Pipeline error {:pipeline_id=>"oracleaudit", :exception=>#<Psych::DisallowedClass: Tried to load unspecified c
lass: Time>, :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/class_loader.rb:99:in `find'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/
gems/psych-5.1.0-java/lib/psych/class_loader.rb:28:in `load'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/scalar_scanner.rb:116:in `parse_time'", "
/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/scalar_scanner.rb:59:in `tokenize'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java
/lib/psych/visitors/to_ruby.rb:69:in `deserialize'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:130:in `visit_Psych_Nodes_Scala
r'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/visitor.rb:30:in `visit'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0
-java/lib/psych/visitors/visitor.rb:6:in `accept'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:35:in `accept'", "/usr/share/log
stash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:320:in `visit_Psych_Nodes_Document'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1
.0-java/lib/psych/visitors/visitor.rb:30:in `visit'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/visitor.rb:6:in `accept'", "/usr/share/lo
gstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych/visitors/to_ruby.rb:35:in `accept'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych.rb
:334:in `safe_load'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/psych-5.1.0-java/lib/psych.rb:369:in `load'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-in
tegration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:115:in `read'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash
/plugin_mixins/jdbc/value_tracking.rb:48:in `common_set_initial'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/
value_tracking.rb:87:in `set_initial'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:31:in `in
itialize'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/plugin_mixins/jdbc/value_tracking.rb:19:in `build_last_value_tracker'", "/
usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/logstash-integration-jdbc-5.4.3/lib/logstash/inputs/jdbc.rb:285:in `register'", "/usr/share/logstash/vendor/bundle/jruby/2.6.0/gems/l
ogstash-mixin-ecs_compatibility_support-1.3.0-java/lib/logstash/plugin_mixins/ecs_compatibility_support/target_check.rb:48:in `register'", "/usr/share/logstash/logstash-core/lib/logst
ash/java_pipeline.rb:237:in `block in register_plugins'", "org/jruby/RubyArray.java:1865:in `each'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:236:in `register_
plugins'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:395:in `start_inputs'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:320:in `start_work
ers'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:194:in `run'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:146:in `block in start'"], "pip
eline.sources"=>["/etc/logstash/pipelines/oracleaudit.conf"], :thread=>"#<Thread:0x451e2ed8 run>"}

If I have exactly one jdbc_input in my pipeline, it works with 8.8.1, but more than one leads to this error.

[lukasertl]

FWIW, logstash 8.8.2 fixes this problem.

[lucabelluccini]

Fixed via #125 (as lukasertl reports, released in 8.8.2).