2019-03-19 10:55:12 +00:00
|
|
|
logger = require 'logger-sharelatex'
|
2019-03-21 14:56:31 +00:00
|
|
|
metrics = require 'metrics-sharelatex'
|
2019-03-19 10:55:12 +00:00
|
|
|
|
|
|
|
# keep track of message counters to detect duplicate and out of order events
|
|
|
|
# messsage ids have the format "UNIQUEHOSTKEY-COUNTER"
|
|
|
|
|
|
|
|
EVENT_LOG_COUNTER = {}
|
|
|
|
EVENT_LOG_TIMESTAMP = {}
|
2019-03-21 14:48:51 +00:00
|
|
|
EVENT_LAST_CLEAN_TIMESTAMP = 0
|
2019-03-19 10:55:12 +00:00
|
|
|
|
|
|
|
module.exports = EventLogger =
|
|
|
|
|
|
|
|
MAX_STALE_TIME_IN_MS: 3600 * 1000
|
|
|
|
|
2019-03-21 14:56:31 +00:00
|
|
|
checkEventOrder: (channel, message_id, message) ->
|
2019-03-19 10:55:12 +00:00
|
|
|
return if typeof(message_id) isnt 'string'
|
2019-03-22 11:18:19 +00:00
|
|
|
return if !(result = message_id.match(/^(.*)-(\d+)$/))
|
|
|
|
key = result[1]
|
|
|
|
count = parseInt(result[2], 0)
|
2019-03-21 14:49:25 +00:00
|
|
|
if !(count >= 0)# ignore checks if counter is not present
|
2019-03-19 10:55:12 +00:00
|
|
|
return
|
|
|
|
# store the last count in a hash for each host
|
|
|
|
previous = EventLogger._storeEventCount(key, count)
|
|
|
|
if !previous? || count == (previous + 1)
|
2019-03-22 11:18:34 +00:00
|
|
|
metrics.inc "event.#{channel}.valid", 0.001 # downsample high rate docupdater events
|
2019-03-19 10:55:12 +00:00
|
|
|
return # order is ok
|
|
|
|
if (count == previous)
|
2019-03-21 14:56:31 +00:00
|
|
|
metrics.inc "event.#{channel}.duplicate"
|
|
|
|
# logger.error {key:key, previous: previous, count:count, message:message}, "duplicate event"
|
2019-03-19 10:55:12 +00:00
|
|
|
return "duplicate"
|
|
|
|
else
|
2019-03-21 14:56:31 +00:00
|
|
|
metrics.inc "event.#{channel}.out-of-order"
|
|
|
|
# logger.error {key:key, previous: previous, count:count, message:message}, "events out of order"
|
2019-03-22 11:19:08 +00:00
|
|
|
return "out-of-order"
|
2019-03-19 10:55:12 +00:00
|
|
|
|
|
|
|
_storeEventCount: (key, count) ->
|
|
|
|
previous = EVENT_LOG_COUNTER[key]
|
|
|
|
now = Date.now()
|
|
|
|
EVENT_LOG_COUNTER[key] = count
|
|
|
|
EVENT_LOG_TIMESTAMP[key] = now
|
|
|
|
# periodically remove old counts
|
2019-03-21 14:48:51 +00:00
|
|
|
if (now - EVENT_LAST_CLEAN_TIMESTAMP) > EventLogger.MAX_STALE_TIME_IN_MS
|
2019-03-19 10:55:12 +00:00
|
|
|
EventLogger._cleanEventStream(now)
|
2019-03-21 14:48:51 +00:00
|
|
|
EVENT_LAST_CLEAN_TIMESTAMP = now
|
2019-03-19 10:55:12 +00:00
|
|
|
return previous
|
|
|
|
|
|
|
|
_cleanEventStream: (now) ->
|
|
|
|
for key, timestamp of EVENT_LOG_TIMESTAMP
|
|
|
|
if (now - timestamp) > EventLogger.MAX_STALE_TIME_IN_MS
|
|
|
|
delete EVENT_LOG_COUNTER[key]
|
|
|
|
delete EVENT_LOG_TIMESTAMP[key]
|