logstash-plugins / logstash-filter-multiline

Apache License 2.0
18 stars 16 forks source link

Fix metadata handling when N>1 sequence of not matched events happen #23

Closed purbon closed 8 years ago

purbon commented 8 years ago

As noted in #22 this will make the metadata to be lost, this is because in the previous_fitler function the metadata is not respected as noted in the changes of this PR. This does not happen in the case of the next filter.

Fixes #22

jsvd commented 8 years ago

Unfortunately this patch introduces (or surfaces ? ) another bug that can be reproduced by the following spec:

 describe "bug with metadata" do
    config <<-CONFIG
    filter {
      mutate { add_field => { "[@metadata][type]" => "test" } }
      multiline {
        pattern => "^test"
        negate => true
        what => "previous"
      }
      mutate { add_field => { "[@metadata][count]" => "1" } }
    }
    CONFIG

    sample ["test", "test"] do
      expect(subject).to be_a(Array)
      puts subject[0].to_hash_with_metadata
      puts subject[1].to_hash_with_metadata
      expect(subject[0]["@metadata"]).to include("count"=>"1")
      expect(subject[1]["@metadata"]).to include("count"=>"1")
    end
  end

Which results in:

% bundle exec rspec spec/filters/multiline_spec.rb  -e bug   
Using Accessor#strict_set for specs
Run options:
  include {:full_description=>/bug/}
  exclude {:redis=>true, :socket=>true, :performance=>true, :couchdb=>true, :elasticsearch=>true, :elasticsearch_secure=>true, :export_cypher=>true, :integration=>true, :windows=>true}
F

Failures:

  1) LogStash::Filters::Multiline bug with metadata "["test","test"]" when processed
     Failure/Error: expect(subject[0]["@metadata"]).to include("count"=>"1")
       expected {"type" => "test", "count" => ["1", "1"]} to include {"count" => "1"}
       Diff:
       @@ -1,2 +1,3 @@
       -[{"count"=>"1"}]
       +"count" => ["1", "1"],
       +"type" => "test",
     # ./spec/filters/multiline_spec.rb:284:in `(root)'
     # /Users/joaoduarte/.rvm/gems/jruby-1.7.22/gems/rspec-wait-0.0.8/lib/rspec/wait.rb:46:in `(root)'

Finished in 0.292 seconds (files took 4.5 seconds to load)
1 example, 1 failure

This happens because in this line the plugin doesn't do a deep copy of the event hash before replacing it in the next line. So, using the to_hash_with_metadata in this PR makes the current event and the pending event to share the same metadata hash, and modifying one's metadata changes the other's :(

purbon commented 8 years ago

@jsvd crap :-1:, good catch. will need to investigate more. I must admit the code looks so cumbersome and strange, it, too much side effects we should minimise.

purbon commented 8 years ago

@jsvd the solution was in the good direction, problem is actually with the overwrite method used that does not handle properly the metadata, making another bunch of metadata lost. updating this pr.

purbon commented 8 years ago

@jsvd updated the PR with a fix for the issue you commented, now looks like metadata is handled better in all filters, let me know what do you think.

jsvd commented 8 years ago

minor comment on whitespace, otherwise LGTM!

purbon commented 8 years ago

ok, will fix identation and merge. thanks for the review @jsvd