Merge pull request #23246 from overleaf/bg-real-time-server-ping

add real-time ping-pong messages for debugging lost connections

GitOrigin-RevId: 28feb8c8c7c660a5a23ca394acd0f69ac828c5a3

services/real-time/app/js/Router.js

@@ -11,6 +11,8 @@ const { UnexpectedArgumentsError } = require('./Errors')
 const Joi = require('joi')
 
 const HOSTNAME = require('node:os').hostname()
+const SERVER_PING_INTERVAL = 15000
+const SERVER_PING_LATENCY_THRESHOLD = 5000
 
 const JOI_OBJECT_ID = Joi.string()
   .required()
@@ -172,6 +174,8 @@ module.exports = Router = {
         }
         return
       }
+      const useServerPing =
+        !!client.handshake?.query?.esh && !!client.handshake?.query?.ssp
       const isDebugging = !!client.handshake?.query?.debugging
       const projectId = client.handshake?.query?.projectId
 
@@ -231,6 +235,64 @@ module.exports = Router = {
         user = { _id: 'anonymous-user', anonymousAccessToken }
       }
 
+      let pingTimestamp
+      let pingId = -1
+      let pongId = -1
+      const pingTimer = useServerPing
+        ? setInterval(function () {
+            if (pongId !== pingId) {
+              logger.warn(
+                {
+                  publicId: client.publicId,
+                  clientId: client.id,
+                  pingId,
+                  pongId,
+                  lastPingTimestamp: pingTimestamp,
+                },
+                'no client response to last ping'
+              )
+            }
+            pingTimestamp = Date.now()
+            client.emit('serverPing', ++pingId, pingTimestamp)
+          }, SERVER_PING_INTERVAL)
+        : null
+      client.on('clientPong', function (receivedPingId, sentTimestamp) {
+        pongId = receivedPingId
+        const receivedTimestamp = Date.now()
+        if (receivedPingId !== pingId) {
+          logger.warn(
+            {
+              publicId: client.publicId,
+              clientId: client.id,
+              receivedPingId,
+              pingId,
+              sentTimestamp,
+              receivedTimestamp,
+              latency: receivedTimestamp - sentTimestamp,
+              lastPingTimestamp: pingTimestamp,
+            },
+            'received pong with wrong counter'
+          )
+        } else if (
+          receivedTimestamp - sentTimestamp >
+          SERVER_PING_LATENCY_THRESHOLD
+        ) {
+          logger.warn(
+            {
+              publicId: client.publicId,
+              clientId: client.id,
+              receivedPingId,
+              pingId,
+              sentTimestamp,
+              receivedTimestamp,
+              latency: receivedTimestamp - sentTimestamp,
+              lastPingTimestamp: pingTimestamp,
+            },
+            'received pong with high latency'
+          )
+        }
+      })
+
       if (settings.exposeHostname) {
         client.on('debug.getHostname', function (callback) {
           if (typeof callback !== 'function') {
@@ -299,6 +361,8 @@ module.exports = Router = {
             { duration, publicId: client.publicId, clientId: client.id },
             'debug client disconnected'
           )
+        } else {
+          clearInterval(pingTimer)
         }
 
         WebsocketController.leaveProject(io, client, function (err) {

services/web/frontend/js/features/ide-react/connection/connection-manager.ts

@@ -80,6 +80,7 @@ export class ConnectionManager extends EventTarget {
     })
     if (externalSocketHeartbeat) {
       query.set('esh', '1')
+      query.set('ssp', '1') // with server-side ping
     }
     const socket = SocketIoShim.connect(parsedURL.origin, {
       resource: parsedURL.pathname.slice(1),
@@ -112,6 +113,9 @@ export class ConnectionManager extends EventTarget {
     socket.on('connectionRejected', err => this.onConnectionRejected(err))
     socket.on('reconnectGracefully', () => this.onReconnectGracefully())
     socket.on('forceDisconnect', (_, delay) => this.onForceDisconnect(delay))
+    socket.on('serverPing', (counter, timestamp) =>
+      this.sendPingResponse(counter, timestamp)
+    )
 
     this.tryReconnect()
   }
@@ -463,4 +467,8 @@ export class ConnectionManager extends EventTarget {
     })
     this.externalHeartbeat.currentStart = t0
   }
+
+  private sendPingResponse(counter?: number, timestamp?: number) {
+    this.socket.emit('clientPong', counter, timestamp)
+  }
 }