nickwallen commented on a change in pull request #1197: METRON-1778
Out-of-order timestamps may delay flush in Storm Profiler
URL: https://github.com/apache/metron/pull/1197#discussion_r260403203
##########
File path:
metron-analytics/metron-profiler-storm/src/main/java/org/apache/metron/profiler/storm/FixedFrequencyFlushSignal.java
##########
@@ -74,31 +72,34 @@ public void reset() {
*/
@Override
public void update(long timestamp) {
+ if(LOG.isWarnEnabled()) {
+ checkIfOutOfOrder(timestamp);
+ }
- if(timestamp > currentTime) {
-
- // need to update current time
- LOG.debug("Updating current time; last={}, new={}", currentTime,
timestamp);
- currentTime = timestamp;
-
- } else if ((currentTime - timestamp) > flushFrequency) {
-
- // significantly out-of-order timestamps
- LOG.warn("Timestamps out-of-order by '{}' ms. This may indicate a
problem in the data. last={}, current={}",
- (currentTime - timestamp),
- timestamp,
- currentTime);
+ if(timestamp < minTime) {
+ minTime = timestamp;
}
- if(flushTime == 0) {
+ if(timestamp > maxTime) {
+ maxTime = timestamp;
+ }
+ }
- // set the next time to flush
- flushTime = currentTime + flushFrequency;
- LOG.debug("Setting flush time; '{}' ms until flush; flushTime={},
currentTime={}, flushFreq={}",
- timeToNextFlush(),
- flushTime,
- currentTime,
- flushFrequency);
+ /**
+ * Checks if the timestamp is significantly out-of-order.
+ *
+ * @param timestamp The last timestamp.
+ */
+ private void checkIfOutOfOrder(long timestamp) {
+ // do not warn if this is the first timestamp we've seen, which will
always be 'out-of-order'
+ if (maxTime > Long.MIN_VALUE) {
+
+ long outOfOrderBy = maxTime - timestamp;
+ if (Math.abs(outOfOrderBy) > flushFrequency) {
Review comment:
Obviously, real-world data is messy. It contains inaccuracies, it arrives
out-of-order, and it generally should not be trusted. Unfortunately, with
event time processing, we are trusting that messy, inaccurate data to control
the advancement of time. Ouch.
Imagine the profiler is running, consuming data, and building profiles.
Consider what happens if one message arrives with an incorrect timestamp, for
example, two days into the future. That will advance time in the Profiler two
days forward. At that point, all of the 'correct' data with the correct
timestamps will be ignored because to the Profiler it looks like it is from two
days ago.
Of course, this will severely skew your profiles. And without at least a
log message, its terribly difficult to understand why that happened. This is a
problem for any system using event time processing, not just the Profiler. I
wanted some way for a user to know about significantly out-of-order telemetry.
To implement this, I needed some threshold to say "if its out-of-order by X,
then issue a warning." Rather than introduce yet another configuration value
for X, I decided to just use the `flushFrequency`. The user will already need
to adjust the flush frequency and window lag based on how out-of-order their
data is. I thought using this existing value as a threshold would work well
enough.
I was also torn between what to do when we get something significantly
out-of-order. We could do any of the following.
1. Log a warning
1. Report an error to the Storm UI
1. Attempt to ignore the out-of-order timestamp
As a first pass, I landed on just a log message. This really shouldn't
happen in practice. We could iterate on this, if we think there are
improvements to be made here.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
[email protected]
With regards,
Apache Git Services
