🔊 Warn when messages are sent before the v1.1 handshake

lib/agent.js

@@ -58,6 +58,11 @@ function Agent(backend, stream) {
   // active, and it is passed to each middleware call
   this.custom = {};
 
+  // The first message received over the connection. Stored to warn if messages
+  // are being sent before the handshake.
+  this._firstReceivedMessage = null;
+  this._handshakeReceived = false;
+
   // Send the legacy message to initialize old clients with the random agent Id
   this.send(this._initMessage(ACTIONS.initLegacy));
 }
@@ -394,6 +399,7 @@ Agent.prototype._handleMessage = function(request, callback) {
   try {
     var errMessage = this._checkRequest(request);
     if (errMessage) return callback(new ShareDBError(ERROR_CODE.ERR_MESSAGE_BADLY_FORMED, errMessage));
+    this._checkFirstMessage(request);
 
     switch (request.a) {
       case ACTIONS.handshake:
@@ -855,6 +861,20 @@ Agent.prototype._handlePresenceData = function(presence) {
   });
 };
 
+Agent.prototype._checkFirstMessage = function(request) {
+  if (this._handshakeReceived) return;
+  if (!this._firstReceivedMessage) this._firstReceivedMessage = request;
+
+  if (request.a === ACTIONS.handshake) {
+    this._handshakeReceived = true;
+    if (this._firstReceivedMessage.a !== ACTIONS.handshake) {
+      logger.warn('Unexpected message received before handshake', this._firstReceivedMessage);
+    }
+    // Release memory
+    this._firstReceivedMessage = null;
+  }
+};
+
 function createClientOp(request, clientId) {
   // src can be provided if it is not the same as the current agent,
   // such as a resubmission after a reconnect, but it usually isn't needed

package.json

@@ -22,7 +22,8 @@
     "ot-json1": "^0.3.0",
     "rich-text": "^4.1.0",
     "sharedb-legacy": "npm:sharedb@=1.1.0",
-    "sinon": "^9.2.4"
+    "sinon": "^9.2.4",
+    "sinon-chai": "^3.7.0"
   },
   "files": [
     "lib/",

test/agent.js

@@ -0,0 +1,74 @@
+var Backend = require('../lib/backend');
+var logger = require('../lib/logger');
+var sinon = require('sinon');
+var StreamSocket = require('../lib/stream-socket');
+var expect = require('chai').expect;
+var ACTIONS = require('../lib/message-actions').ACTIONS;
+var Connection = require('../lib/client/connection');
+var LegacyConnection = require('sharedb-legacy/lib/client').Connection;
+
+describe('Agent', function() {
+  var backend;
+
+  beforeEach(function() {
+    backend = new Backend();
+  });
+
+  afterEach(function(done) {
+    backend.close(done);
+  });
+
+  describe('handshake', function() {
+    it('warns when messages are sent before the handshake', function(done) {
+      var socket = new StreamSocket();
+      var stream = socket.stream;
+      backend.listen(stream);
+      sinon.spy(logger, 'warn');
+      socket.send(JSON.stringify({a: ACTIONS.subscribe, c: 'dogs', d: 'fido'}));
+      var connection = new Connection(socket);
+      socket._open();
+      connection.once('connected', function() {
+        expect(logger.warn).to.have.been.calledOnceWithExactly(
+          'Unexpected message received before handshake',
+          {a: ACTIONS.subscribe, c: 'dogs', d: 'fido'}
+        );
+        done();
+      });
+    });
+
+    it('does not warn when messages are sent after the handshake', function(done) {
+      var socket = new StreamSocket();
+      var stream = socket.stream;
+      var agent = backend.listen(stream);
+      sinon.spy(logger, 'warn');
+      var connection = new Connection(socket);
+      socket._open();
+      connection.once('connected', function() {
+        socket.send(JSON.stringify({a: ACTIONS.subscribe, c: 'dogs', d: 'fido'}));
+        expect(logger.warn).not.to.have.been.called;
+        expect(agent._firstReceivedMessage).to.be.null;
+        done();
+      });
+    });
+
+    it('does not warn for clients on protocol v1.0', function(done) {
+      backend.use('receive', function(request, next) {
+        var error = null;
+        if (request.data.a === ACTIONS.handshake) error = new Error('Unexpected handshake');
+        next(error);
+      });
+      var socket = new StreamSocket();
+      var stream = socket.stream;
+      backend.listen(stream);
+      sinon.spy(logger, 'warn');
+      socket.send(JSON.stringify({a: ACTIONS.subscribe, c: 'dogs', d: 'fido'}));
+      var connection = new LegacyConnection(socket);
+      socket._open();
+      connection.get('dogs', 'fido').fetch(function(error) {
+        if (error) return done(error);
+        expect(logger.warn).not.to.have.been.called;
+        done();
+      });
+    });
+  });
+});

test/setup.js

@@ -1,5 +1,9 @@
 var logger = require('../lib/logger');
 var sinon = require('sinon');
+var sinonChai = require('sinon-chai');
+var chai = require('chai');
+
+chai.use(sinonChai);
 
 if (process.env.LOGGING !== 'true') {
   // Silence the logger for tests by setting all its methods to no-ops