From 2a311392541d2d2e41a36e7249757beed5c1a92b Mon Sep 17 00:00:00 2001
From: Brian Gough <brian.gough@overleaf.com>
Date: Thu, 11 Apr 2019 12:53:43 +0100
Subject: [PATCH] log and skip duplicate events

---
 .../app/coffee/DocumentUpdaterController.coffee          | 9 ++++++++-
 services/real-time/app/coffee/EventLogger.coffee         | 4 ++--
 .../real-time/app/coffee/WebsocketLoadBalancer.coffee    | 7 ++++++-
 3 files changed, 16 insertions(+), 4 deletions(-)

diff --git a/services/real-time/app/coffee/DocumentUpdaterController.coffee b/services/real-time/app/coffee/DocumentUpdaterController.coffee
index a2bd3f3e77..057649aa9c 100644
--- a/services/real-time/app/coffee/DocumentUpdaterController.coffee
+++ b/services/real-time/app/coffee/DocumentUpdaterController.coffee
@@ -24,7 +24,9 @@ module.exports = DocumentUpdaterController =
 				return
 			if message.op?
 				if message._id?
-					EventLogger.checkEventOrder("applied-ops", message._id, message)
+					status = EventLogger.checkEventOrder("applied-ops", message._id, message)
+					if status is 'duplicate'
+						return # skip duplicate events
 				DocumentUpdaterController._applyUpdateFromDocumentUpdater(io, message.doc_id, message.op)
 			else if message.error?
 				DocumentUpdaterController._processErrorFromDocumentUpdater(io, message.doc_id, message.error, message)
@@ -33,6 +35,11 @@ module.exports = DocumentUpdaterController =
 
 	_applyUpdateFromDocumentUpdater: (io, doc_id, update) ->
 		clientList = io.sockets.clients(doc_id)
+		# avoid unnecessary work if no clients are connected
+		if clientList.length is 0
+			return
+		# send updates to clients
+		logger.log doc_id: doc_id, version: update.v, source: update.meta?.source, socketIoClients: (client.id for client in clientList), "distributing updates to clients"
 		seen = {}
 		# send messages only to unique clients (due to duplicate entries in io.sockets.clients)
 		for client in clientList when not seen[client.id]
diff --git a/services/real-time/app/coffee/EventLogger.coffee b/services/real-time/app/coffee/EventLogger.coffee
index 3baf734ead..3738e4f729 100644
--- a/services/real-time/app/coffee/EventLogger.coffee
+++ b/services/real-time/app/coffee/EventLogger.coffee
@@ -26,11 +26,11 @@ module.exports = EventLogger =
 			return # order is ok
 		if (count == previous)
 			metrics.inc "event.#{channel}.duplicate"
-			# logger.error {key:key, previous: previous, count:count, message:message}, "duplicate event"
+			logger.warn {channel:channel, message_id:message_id}, "duplicate event"
 			return "duplicate"
 		else
 			metrics.inc "event.#{channel}.out-of-order"
-			# logger.error {key:key, previous: previous, count:count, message:message}, "events out of order"
+			logger.warn {channel:channel, message_id:message_id, key:key, previous: previous, count:count}, "out of order event"
 			return "out-of-order"
 
 	_storeEventCount: (key, count) ->
diff --git a/services/real-time/app/coffee/WebsocketLoadBalancer.coffee b/services/real-time/app/coffee/WebsocketLoadBalancer.coffee
index 4095e36e68..3e973fdb4c 100644
--- a/services/real-time/app/coffee/WebsocketLoadBalancer.coffee
+++ b/services/real-time/app/coffee/WebsocketLoadBalancer.coffee
@@ -38,9 +38,14 @@ module.exports = WebsocketLoadBalancer =
 				io.sockets.emit(message.message, message.payload...)
 			else if message.room_id?
 				if message._id?
-					EventLogger.checkEventOrder("editor-events", message._id, message)
+					status = EventLogger.checkEventOrder("editor-events", message._id, message)
+					if status is "duplicate"
+						return # skip duplicate events
 				# send messages only to unique clients (due to duplicate entries in io.sockets.clients)
 				clientList = io.sockets.clients(message.room_id)
+				# avoid unnecessary work if no clients are connected
+				return if clientList.length is 0
+				logger.log {channel:channel, message: message.message, room_id: message.room_id, message_id: message._id, socketIoClients: (client.id for client in clientList)}, "distributing event to clients"
 				seen = {}
 				for client in clientList when not seen[client.id]
 					seen[client.id] = true