newrelic_spec.rb in logstash-output-newrelic-1.0.3

- old
+ new

@@ -22,10 +22,17 @@
       "retry_seconds" => retry_seconds,
       "max_delay" => max_delay,
     }
   }
 
+  # An arbitrary time to use in these tests, with different representations
+  class FixedTime
+    MILLISECONDS = 1562888528123
+    ISO_8601_STRING_TIME = '2019-07-11T23:42:08.123Z'
+    LOGSTASH_TIMESTAMP = LogStash::Timestamp.coerce(ISO_8601_STRING_TIME)
+  end
+
   def gunzip(bytes)
     gz = Zlib::GzipReader.new(StringIO.new(bytes))
     gz.read
   end
 
@@ -37,10 +44,20 @@
 
   def multiple_gzipped_messages(body)
     JSON.parse(gunzip(body))
   end
 
+  def now_in_milliseconds()
+    (Time.now.to_f * 1000).to_i # to_f gives seconds with a fractional portion
+  end
+
+  def within_five_seconds_of(time_in_millis, expected_in_millis)
+    five_seconds_in_millis = 5 * 1000
+    (time_in_millis - expected_in_millis).abs < five_seconds_in_millis
+  end
+
+
   before(:each) do
     @newrelic_output = LogStash::Plugin.lookup("output", "newrelic").new(simple_config)
     @newrelic_output.register
   end
 
@@ -59,21 +76,22 @@
 
   context "request headers" do
     it "all present" do
       stub_request(:any, base_uri).to_return(status: 200)
 
-      event = LogStash::Event.new({ "message" => "Test message" })
+      event = LogStash::Event.new({:message => "Test message" })
       @newrelic_output.multi_receive([event])
 
       wait_for(a_request(:post, base_uri)
         .with(headers: {
                 "X-Insert-Key" => api_key,
                 "X-Event-Source" => "logs",
                 "Content-Encoding" => "gzip",
               })).to have_been_made
     end
   end
+
   context "request body" do
 
     it "message contains plugin information" do
       stub_request(:any, base_uri).to_return(status: 200)
 
@@ -86,20 +104,51 @@
         data['common']['attributes']['plugin']['type'] == 'logstash' &&
         data['common']['attributes']['plugin']['version'] == LogStash::Outputs::NewRelicVersion::VERSION })
       .to have_been_made
     end
 
-    # TODO: why is this field always removed?
-    it "'@timestamp' field is removed" do
-      stub_request(:any, base_uri).to_return(status: 200)
 
-      event = LogStash::Event.new({ :message => "Test message", :@timestamp => '123' })
-      @newrelic_output.multi_receive([event])
+    context "@timestamp field" do
 
-      wait_for(a_request(:post, base_uri)
-        .with { |request| single_gzipped_message(request.body)['@timestamp'] == nil })
-        .to have_been_made
+      def test_timestamp(timestamp, message_matcher)
+        stub_request(:any, base_uri).to_return(status: 200)
+
+        event = LogStash::Event.new({ :message => "Test message", :@timestamp => timestamp })
+        @newrelic_output.multi_receive([event])
+
+        wait_for(a_request(:post, base_uri)
+                     .with { |request|
+                       message = single_gzipped_message(request.body)
+                       message_matcher.call(message)
+                     }).to have_been_made
+      end
+
+      it "LogStash::Timestamp '@timestamp' field is added as 'timestamp' as milliseconds since epoch" do
+        def message_matcher(message)
+          message['timestamp'] == FixedTime::MILLISECONDS
+        end
+
+        test_timestamp(FixedTime::LOGSTASH_TIMESTAMP, method(:message_matcher))
+      end
+
+      it "String ISO 8601 '@timestamp' field is added as 'timestamp' as milliseconds since epoch" do
+        def message_matcher(message)
+          message['timestamp'] == FixedTime::MILLISECONDS
+        end
+
+        test_timestamp(FixedTime::ISO_8601_STRING_TIME, method(:message_matcher))
+      end
+
+      # Ideally we might not even set a timestamp if parsing fails. However, the time parsing library doesn't tell us if
+      # parsing fails -- it just returns the current time.
+      it "Unparseable '@timestamp' field is parsed as current time and put into 'timestamp'" do
+        def message_matcher(message)
+          within_five_seconds_of(message['timestamp'], now_in_milliseconds)
+        end
+
+        test_timestamp("Not an ISO 8601 string", method(:message_matcher))
+      end
     end
 
     it "all other fields passed through as is" do
       stub_request(:any, base_uri).to_return(status: 200)
 
@@ -107,10 +156,9 @@
       @newrelic_output.multi_receive([event])
 
       wait_for(a_request(:post, base_uri)
         .with { |request|
           message = single_gzipped_message(request.body)
-          puts message
           message['message'] == 'Test message' &&
           message['attributes']['other'] == 'Other value' })
         .to have_been_made
     end
 