Added ability to specify timestamp in message #125

consulthys · 2017-02-21T08:30:40Z

This is a quick fix for #124 in order to be able to add a specific timestamp to messages sunk to Kafka topics.

talevy · 2017-02-21T18:48:12Z

logstash-output-kafka.gemspec

@@ -1,7 +1,7 @@
 Gem::Specification.new do |s|

  s.name            = 'logstash-output-kafka'
-  s.version         = '6.1.4'
+  s.version         = '6.1.5'


since this is a new feature and not just a bug fix. I'd be happy to bump this to 6.2.0

No prob, makes sense, I will do.

charsyam · 2017-07-14T13:34:56Z

+1

thinker0 · 2017-07-14T14:30:13Z

+1

henridf · 2017-09-04T07:48:11Z

Looks good to me, any chance this can be reviewed by the core team? Sorely needing it (and Kafka support is surprisingly weak across the board in log shipping tools).

jinleileiking · 2017-09-12T07:44:33Z

+1

jordansissel · 2017-09-12T09:04:27Z

The code looks OK, but this needs to be rebased.

Also needs docs added in docs/index.asciidoc

jordansissel · 2017-09-12T09:10:11Z

@consulthys I think @talevy's original comment applies here. This should be a minor version bump (not patch).

Regarding the docs, having the docs in docs/index.asciidoc is somewhat new for plugins, so let me know if you run into troubles with it.

consulthys · 2017-09-12T09:14:52Z

@jordansissel I've resolved the conflicts, amended the docs and bumped the minor version. Let me know if you want me to do anything else.

jordansissel · 2017-09-12T09:18:51Z

lib/logstash/outputs/kafka.rb

+        unless @message_timestamp.nil?
+          if event.include? @message_timestamp
+            ts = event.get(@message_timestamp)
+            timestamp = ts.is_a?(LogStash::Timestamp) ? ts.time.to_i : ts.to_i


LogStash::Timestamp#to_i returns 'seconds since epoch':

[6] pry(#<LogStash::Runner>)> LogStash::Event.new.timestamp.to_i => 1505207654

But the Kafka RFC indicates in a few places that the unit for the Long timestamp is milliseconds, not seconds.

I think you need (ts.to_f * 1000).to_i to convert to milliseconds.

Note that I'm not calling to_i on a Logstash::Timestamp, but on the wrapped Joda DateTime object and I was under the impression that back then it returned milliseconds, but agreed, not anymore. I'll change that.

Yeah, I checked timestamp.time and in Logstash 5.x, at least, it is a ruby Time object:

[6] pry(#<LogStash::Runner>)> date = LogStash::Filters::Date.new("match" => [ "message", "ISO8601" ]) => <LogStash::Filters::Date match=>["message", "ISO8601"], id=>"date_e40418e5-e0ba-4b0f-a3a5-a04b62920d0e", enable_metric=>true, periodic_flush=>false, target=>"@timestamp", tag_on_failure=>["_dateparsefailure"]> [7] pry(#<LogStash::Runner>)> e = LogStash::Event.new => 2017-09-13T04:11:30.230Z %{host} %{message} [8] pry(#<LogStash::Runner>)> e.timestamp.time.to_i => 1505275890 [9] pry(#<LogStash::Runner>)> e.timestamp.time.class => Time # Now try applying the date filter: [11] pry(#<LogStash::Runner>)> e.set("message", "2017-01-01T00:00:00.000Z") => "2017-01-01T00:00:00.000Z" [12] pry(#<LogStash::Runner>)> date.filter(e) => 2017-01-01T00:00:00.000Z %{host} 2017-01-01T00:00:00.000Z [13] pry(#<LogStash::Runner>)> e.timestamp.time.to_i => 1483228800 [14] pry(#<LogStash::Runner>)> e.timestamp.time.class => Time ^^^ Still a Time object.

Internally, a LogStash::Event is a wrapper of the internal org.logstash.Event, and both have a Timestamp class. In Jruby, this timestamp type is provided by JrubyTimestampExtLibrary.java which has a ruby time method that returns a ruby Time object.

So, from Ruby, due to our Jruby wrappers, you don't get to see the org.logstash.Timestamp object (which is backed by Joda DateTime type), you see a Ruby Time type.

True, I made the same exploration and came to the same conclusion.

Still, I'm a bit surprised that one has to do such a transformation in order to get a millisecond value out of a LogStash::Timestamp. Even more surprising is the fact that nowhere else in the whole Logstash codebase something like this is needed. And if my previous statement is wrong (which I hope), then why isn't there a utility method somewhere that gets me that value?

I don't know anywhere else we need to output milliseconds-since-epoch. I checked a few places I know we use time that isn't ISO8601 formatted:

Nagios output uses seconds-since-epoch (not milliseconds)

Graphite output uses seconds-since-epoch

Influxdb output supports custom time precision (microseconds up to hours)

Ok, thanks for checking. I was under the impression that getting a milliseconds representation out of a date/timestamp was a common feature in most mainstream languages.

I actually found one place in the Logstash core lib that does the same transformation and could benefit from having that factored out into the TimeStamp class: https://github.com/elastic/logstash/blob/master/logstash-core/lib/logstash/agent.rb#L182

If not feasible, I'll just apply your suggestion above so we can let it be.

jordansissel · 2017-09-12T09:19:57Z

lib/logstash/outputs/kafka.rb

+            ts = event.get(@message_timestamp)
+            timestamp = ts.is_a?(LogStash::Timestamp) ? ts.time.to_i : ts.to_i
+          else
+            timestamp = event.sprintf(@message_timestamp).to_i


what is the goal here? I can see this very easily causing mistakes for users. What would an expected sprintf be, here?

"%{+%s}%{+SSS}" (same result as if you call time.to_f * 1000 basically)

Something else?

The idea of using sprintf here was described in my original issue (#124), but quick, it was helpful in cases where a field containing a value in seconds could also be used as the message timestamp.

I must have missed this comment; sorry for the delays.

If the use case is taking a numeric value as the kafka message timestamp, then I would prefer this be event.get(@message_timestamp) and not event.sprintf.

jinleileiking · 2017-09-12T12:30:55Z

waiting for merged

jordansissel · 2017-09-12T19:52:48Z

@consulthys I left some inline comments in review with the main question being if the timestamp used was correct. Based on my reading of the kafka docs, the timestamp is milliseconds and this PR uses seconds (Time#to_i gives seconds-since-epoch). It's unclear to me from the Kafka docs what origin the ProducerMessage timestamp has (unix epoch? process start time? system boot time? something else?)

After some digging, I think I finally found the answer. In KAFKA-3025 it says this:

Timestamp is the number of milliseconds since Unix Epoch

jinleileiking · 2017-09-13T01:41:30Z

No this patch. No elk for ksql

consulthys · 2017-09-13T03:44:38Z

Thanks @jordansissel, it's been months since I developed that so I'll have another look in details shortly :-)

jordansissel · 2017-09-13T04:19:36Z

Confession: I found the Time(Ruby) vs DateTime(Joda) to be confusing. I think we kept Time (Ruby) for backwards compatibility having event.timestamp have a predictable and backwards-compatible interface as we were building the new Java internals.

jinleileiking · 2017-09-25T01:53:39Z

@jordansissel can it be merged ?

jinleileiking · 2017-11-15T05:47:02Z

Not merged?

jinleileiking · 2017-11-15T05:47:21Z

@jordansissel

jordansissel · 2017-11-15T06:28:18Z

@jinleileiking Looking at the recent comments, there is still review going on in this issue. If you wish invest in speeding this up, help with testing, reviewing, or with code is always appreciated.

consulthys · 2017-11-15T06:35:50Z

@jordansissel I commented your change request but didn't get any feedback. Once you do, I'll make sure to wrap this up. Thanks much!

jinleileiking · 2017-11-20T03:01:55Z

I want to test it in my env, seems not work with logstash 2.4.0

guyboertje · 2017-12-22T17:39:23Z

@consulthys
It looks like another rebase is needed.

@jordansissel
Is Valentin's replies to your questions satisfactory?

neerav-salaria-guavus · 2018-05-31T11:48:40Z

Any update on this change to be merged @consulthys @jordansissel .

daggerjames · 2019-11-26T08:55:59Z

still waiting .

consulthys added 2 commits February 21, 2017 09:25

Added ability to specify timestamp in message

ab2548e

Added ability to specify timestamp in message (fixed tests)

1a7d908

talevy reviewed Feb 21, 2017

View reviewed changes

consulthys added 2 commits February 21, 2017 19:59

Bump to 6.2.0

f118602

Added ability to specify timestamp in message (added more tests)

85746ed

Merge branch 'master' into master

9b0c36f

consulthys added 3 commits September 12, 2017 11:12

Added doc for message_timestamp field

4424c51

Minor version bump

862e6e0

Minor version bump

a08e36d

jordansissel suggested changes Sep 12, 2017

View reviewed changes

jsvd added the enhancement label Jan 15, 2018

jsvd added the adoptme label Jan 15, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Added ability to specify timestamp in message #125

Added ability to specify timestamp in message #125

consulthys commented Feb 21, 2017

talevy Feb 21, 2017

consulthys Feb 21, 2017

charsyam commented Jul 14, 2017

thinker0 commented Jul 14, 2017

henridf commented Sep 4, 2017 •

edited

Loading

jinleileiking commented Sep 12, 2017

jordansissel commented Sep 12, 2017

jordansissel commented Sep 12, 2017

consulthys commented Sep 12, 2017

jordansissel Sep 12, 2017

consulthys Sep 13, 2017

jordansissel Sep 13, 2017

consulthys Sep 13, 2017

jordansissel Sep 14, 2017

consulthys Sep 15, 2017

jordansissel Sep 12, 2017

consulthys Sep 13, 2017

jordansissel Dec 28, 2017

jinleileiking commented Sep 12, 2017

jordansissel commented Sep 12, 2017

jinleileiking commented Sep 13, 2017

consulthys commented Sep 13, 2017

jordansissel commented Sep 13, 2017

jinleileiking commented Sep 25, 2017

jinleileiking commented Nov 15, 2017

jinleileiking commented Nov 15, 2017

jordansissel commented Nov 15, 2017

consulthys commented Nov 15, 2017

jinleileiking commented Nov 20, 2017

guyboertje commented Dec 22, 2017

neerav-salaria-guavus commented May 31, 2018

daggerjames commented Nov 26, 2019

Added ability to specify timestamp in message #125

Are you sure you want to change the base?

Added ability to specify timestamp in message #125

Conversation

consulthys commented Feb 21, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

charsyam commented Jul 14, 2017

thinker0 commented Jul 14, 2017

henridf commented Sep 4, 2017 • edited Loading

jinleileiking commented Sep 12, 2017

jordansissel commented Sep 12, 2017

jordansissel commented Sep 12, 2017

consulthys commented Sep 12, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jinleileiking commented Sep 12, 2017

jordansissel commented Sep 12, 2017

jinleileiking commented Sep 13, 2017

consulthys commented Sep 13, 2017

jordansissel commented Sep 13, 2017

jinleileiking commented Sep 25, 2017

jinleileiking commented Nov 15, 2017

jinleileiking commented Nov 15, 2017

jordansissel commented Nov 15, 2017

consulthys commented Nov 15, 2017

jinleileiking commented Nov 20, 2017

guyboertje commented Dec 22, 2017

neerav-salaria-guavus commented May 31, 2018

daggerjames commented Nov 26, 2019

henridf commented Sep 4, 2017 •

edited

Loading