Fix: DLQ expects us to pass down an event (#1012)

resolves a DLQ regression shipped in 11.0.0 (#1013)

Author: kares

CHANGELOG.md

@@ -1,4 +1,5 @@
 ## 11.0.1
+ - Fix: DLQ regression shipped in 11.0.0 [#1012](https://github.com/logstash-plugins/logstash-output-elasticsearch/pull/1012)
  - [DOC] Fixed broken link in list item [#1011](https://github.com/logstash-plugins/logstash-output-elasticsearch/pull/1011)
 
 ## 11.0.0

lib/logstash/outputs/elasticsearch.rb

@@ -392,7 +392,21 @@ def event_action_tuple(event)
     params[:version] = event.sprintf(@version) if @version
     params[:version_type] = event.sprintf(@version_type) if @version_type
 
-    [action, params, event.to_hash]
+    EventActionTuple.new(action, params, event)
+  end
+
+  class EventActionTuple < Array # TODO: acting as an array for compatibility
+
+    def initialize(action, params, event, event_data = nil)
+      super(3)
+      self[0] = action
+      self[1] = params
+      self[2] = event_data || event.to_hash
+      @event = event
+    end
+
+    attr_reader :event
+
   end
 
   # @return Hash (initial) parameters for given event

lib/logstash/outputs/elasticsearch/data_stream_support.rb

@@ -146,7 +146,7 @@ def data_stream_default(data_stream_params, valid_data_stream_config)
     def data_stream_event_action_tuple(event)
       event_data = event.to_hash
       data_stream_event_sync(event_data) if data_stream_sync_fields
-      ['create', common_event_params(event), event_data] # action always 'create'
+      EventActionTuple.new('create', common_event_params(event), event, event_data)
     end
 
     DATA_STREAM_SYNC_FIELDS = [ 'type', 'dataset', 'namespace' ].freeze

lib/logstash/plugin_mixins/elasticsearch/common.rb

@@ -200,8 +200,9 @@ def next_sleep_interval(current_interval)
     def handle_dlq_status(message, action, status, response)
       # To support bwc, we check if DLQ exists. otherwise we log and drop event (previous behavior)
       if @dlq_writer
+        event, action = action.event, [action[0], action[1], action[2]]
         # TODO: Change this to send a map with { :status => status, :action => action } in the future
-        @dlq_writer.write(action[2], "#{message} status: #{status}, action: #{action}, response: #{response}")
+        @dlq_writer.write(event, "#{message} status: #{status}, action: #{action}, response: #{response}")
       else
         if dig_value(response, 'index', 'error', 'type') == 'invalid_index_name_exception'
           level = :error

spec/unit/outputs/elasticsearch_spec.rb

@@ -343,7 +343,7 @@
                               }
                     }]
         }
-    end
+      end
 
       before(:each) do
         allow(subject.client).to receive(:bulk_send).with(instance_of(StringIO), instance_of(Array)) do |stream, actions|
@@ -771,9 +771,9 @@
 
         context 'when getting any other exception' do
           it 'should log at WARN level' do
-            dlog = double_logger = double("logger").as_null_object
-            subject.instance_variable_set(:@logger, dlog)
-            expect(dlog).to receive(:warn).with(/Could not index/, hash_including(:status, :action, :response))
+            logger = double("logger").as_null_object
+            subject.instance_variable_set(:@logger, logger)
+            expect(logger).to receive(:warn).with(/Could not index/, hash_including(:status, :action, :response))
             mock_response = { 'index' => { 'error' => { 'type' => 'illegal_argument_exception' } } }
             subject.handle_dlq_status("Could not index event to Elasticsearch.",
               [:action, :params, :event], :some_status, mock_response)
@@ -782,9 +782,9 @@
 
         context 'when the response does not include [error]' do
           it 'should not fail, but just log a warning' do
-            dlog = double_logger = double("logger").as_null_object
-            subject.instance_variable_set(:@logger, dlog)
-            expect(dlog).to receive(:warn).with(/Could not index/, hash_including(:status, :action, :response))
+            logger = double("logger").as_null_object
+            subject.instance_variable_set(:@logger, logger)
+            expect(logger).to receive(:warn).with(/Could not index/, hash_including(:status, :action, :response))
             mock_response = { 'index' => {} }
             expect do
               subject.handle_dlq_status("Could not index event to Elasticsearch.",
@@ -804,12 +804,55 @@
       # We should still log when sending to the DLQ.
       # This shall be solved by another issue, however: logstash-output-elasticsearch#772
       it 'should send the event to the DLQ instead, and not log' do
-        expect(dlq_writer).to receive(:write).once.with(:event, /Could not index/)
+        event = LogStash::Event.new("foo" => "bar")
+        expect(dlq_writer).to receive(:write).once.with(event, /Could not index/)
         mock_response = { 'index' => { 'error' => { 'type' => 'illegal_argument_exception' } } }
-        subject.handle_dlq_status("Could not index event to Elasticsearch.",
-          [:action, :params, :event], :some_status, mock_response)
+        action = LogStash::Outputs::ElasticSearch::EventActionTuple.new(:action, :params, event)
+        subject.handle_dlq_status("Could not index event to Elasticsearch.", action, 404, mock_response)
       end
     end
+
+    context 'with response status 400' do
+
+      let(:options) { super().merge 'document_id' => '%{foo}' }
+
+      let(:events) { [ LogStash::Event.new("foo" => "bar") ] }
+
+      let(:dlq_writer) { subject.instance_variable_get(:@dlq_writer) }
+
+      let(:bulk_response) do
+        {
+            "took"=>1, "ingest_took"=>11, "errors"=>true, "items"=>
+            [{
+                 "index"=>{"_index"=>"bar", "_type"=>"_doc", "_id"=>'bar', "status"=>400,
+                           "error"=>{"type" => "illegal_argument_exception", "reason" => "TEST" }
+                  }
+            }]
+        }
+      end
+
+      before(:each) do
+        allow(subject.client).to receive(:bulk_send).and_return(bulk_response)
+      end
+
+      it "should write event to DLQ" do
+        expect(dlq_writer).to receive(:write).and_wrap_original do |method, *args|
+          expect( args.size ).to eql 2
+
+          event, reason = *args
+          expect( event ).to be_a LogStash::Event
+          expect( event ).to be events.first
+          expect( reason ).to start_with 'Could not index event to Elasticsearch. status: 400, action: ["index"'
+          expect( reason ).to match /_id=>"bar".*"foo"=>"bar".*response:.*"reason"=>"TEST"/
+
+          method.call(*args) # won't hurt to call LogStash::Util::DummyDeadLetterQueueWriter
+        end.once
+
+        event_action_tuples = subject.map_events(events)
+        subject.send(:submit, event_action_tuples)
+      end
+
+    end if LOGSTASH_VERSION > '7.0'
   end
 
   describe "custom headers" do