logstash-plugins / logstash-input-gelf

Apache License 2.0
20 stars 39 forks source link

Fix crash when receive a BigDecimal inside `_@timestamp` #67

Closed wpjunior closed 2 years ago

wpjunior commented 3 years ago

The UDP server crashes when receives a GELF message like that {"full_message": "my message", "_@timestamp": 12345678889}

I wrote a test case to show that behavior.

Thanks


Release notes

Safe parsing of _@timestamp to avoid crashing the plugin and Logstash

What does this PR do?

This PR safely cast the values of _@timestamp field in GELF and in case of error skip the event, avoiding Logstash crash

Why is it important/What is the impact to the user?

Permit to handle correctly the numerical values in _@timestamp without stopping Logstash process in case of error.

Checklist

Author's Checklist

How to test this PR locally

output { stdout { codec => rubydebug { metadata => true } } }

- provide some input from another shell:

echo -n '{ "version": "1.1", "host": "example.org", "shortmessage": "A short message", "level": 5, "@timestamp": "foo" }' | nc -u -w0 127.0.0.1 3333

- Logstash skip the message and doesn't crash

## Related issues

<!-- Recommended
Link related issues below. Insert the issue link or reference after the word "Closes" if merging this should automatically close it.

- Closes #123
- Relates #123
- Requires #123
- Superseeds #123
-->
- 

## Use cases

<!-- Recommended
Explain here the different behaviors that this PR introduces or modifies in this project, user roles, environment configuration, etc.

If you are familiar with Gherkin test scenarios, we recommend its usage: https://cucumber.io/docs/gherkin/reference/
-->
A user send GELF messages in the form:
```json
{ "version": "1.1", "host": "example.org", "short_message": "A short message", "level": 5, "_@timestamp": "foo" }

and the parsing of such payload can't crash Logstash.

Logs

[2021-11-16T09:22:14,240][WARN ][org.logstash.Event       ][main][a966e44cc4978c04ea63b0e0fba28400454ae6cbcc52f24abaade32528a0a352] Unrecognized @timestamp value type=class org.jruby.RubyFixnum
warning: thread "Ruby-0-Thread-34: :1" terminated with exception (report_on_exception is true):
TypeError: wrong argument type Integer (expected LogStash::Timestamp)
                       set at org/logstash/ext/JrubyEventExtLibrary.java:122
  strip_leading_underscore at /home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:273
                      each at org/jruby/RubyArray.java:1821
  strip_leading_underscore at /home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:271
              udp_listener at /home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:210
                       run at /home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:79
[2021-11-16T09:22:14,265][ERROR][logstash.javapipeline    ][main][a966e44cc4978c04ea63b0e0fba28400454ae6cbcc52f24abaade32528a0a352] A plugin had an unrecoverable error. Will restart this plugin.
  Pipeline_id:main
  Plugin: <LogStash::Inputs::Gelf port=>3333, id=>"a966e44cc4978c04ea63b0e0fba28400454ae6cbcc52f24abaade32528a0a352", enable_metric=>true, codec=><LogStash::Codecs::Plain id=>"plain_26d156d8-c393-41b3-8cde-08392c473c27", enable_metric=>true, charset=>"UTF-8">, host=>"0.0.0.0", remap=>true, strip_leading_underscore=>true, use_tcp=>false, use_udp=>true>
  Error: wrong argument type Integer (expected LogStash::Timestamp)
  Exception: TypeError
  Stack: org/logstash/ext/JrubyEventExtLibrary.java:122:in `set'
/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:273:in `block in strip_leading_underscore'
org/jruby/RubyArray.java:1821:in `each'
/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:271:in `strip_leading_underscore'
/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:210:in `udp_listener'
/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:79:in `block in run'
[2021-11-16T09:22:14,314][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<TypeError: wrong argument type Integer (expected LogStash::Timestamp)>, :backtrace=>["org/logstash/ext/JrubyEventExtLibrary.java:122:in `set'", "/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:273:in `block in strip_leading_underscore'", "org/jruby/RubyArray.java:1821:in `each'", "/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:271:in `strip_leading_underscore'", "/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:210:in `udp_listener'", "/home/andrea/workspace/logstash_andsel/vendor/bundle/jruby/2.5.0/gems/logstash-input-gelf-3.3.0/lib/logstash/inputs/gelf.rb:79:in `block in run'"]}
[2021-11-16T09:22:14,322][FATAL][org.logstash.Logstash    ] Logstash stopped processing because of an error: (SystemExit) exit
org.jruby.exceptions.SystemExit: (SystemExit) exit
    at org.jruby.RubyKernel.exit(org/jruby/RubyKernel.java:747) ~[jruby-complete-9.2.20.0.jar:?]
    at org.jruby.RubyKernel.exit(org/jruby/RubyKernel.java:710) ~[jruby-complete-9.2.20.0.jar:?]
    at home.andrea.workspace.logstash_andsel.lib.bootstrap.environment.<main>(/home/andrea/workspace/logstash_andsel/lib/bootstrap/environment.rb:94) ~[?:?]
cla-checker-service[bot] commented 3 years ago

💚 CLA has been signed

pedrokiefer commented 3 years ago

@jsvd any chance that this PR gets merged?

jsvd commented 3 years ago

Hi folks, what if we just handled this special case: if the stripped key is "@timestamp", convert the value to LogStash::Timestamp, and if that fails, convert it to BigDecimal? For example:

 def strip_leading_underscore(event)
     # Map all '_foo' fields to simply 'foo'
     event.to_hash.keys.each do |key|
       next unless key[0,1] == "_"
       new_key = key[1..-1]
       value = event.get(key)
       if new_key == LogStash::Event::TIMESTAMP
         event.set(new_key, coerce_timestamp_carefully(value))
       else
         event.set(new_key, value)
       end
       event.remove(key)
     end
  end

  def coerce_timestamp_carefully(value)
    LogStash::Timestamp.at(value)
  rescue TypeError => e
    # maybe it's a BigDecimal?
    coerced_value = BigDecimal.new(value)
    LogStash::Timestamp.at(coerced_value)
  end
andsel commented 2 years ago

I think could be the right path but also the coercion of the BigDecimal could make the pipeline crash. Considering the piece:

coerced_value = BigDecimal.new(value)

if value is a malformed String for example "foo" then it raises a NumberFormatException so in that case the event should be dropped

andsel commented 2 years ago

@yaauie I like the idea to tag the event instead of dropping with log. I think we can't do event.tag("_gelf_move_field_failure", "<reason>") according to https://github.com/elastic/logstash/blob/65e163fc5b5fa6a9d25a2272b3d075f112a8cb61/logstash-core/src/main/java/org/logstash/ext/JrubyEventExtLibrary.java#L285-L291 so should we add another subfield in @metadata to fill with the reason?

mfilocha commented 2 years ago

This fix very likely breaks logstash: https://github.com/logstash-plugins/logstash-input-gelf/issues/70