channel: Delay notifications to avoid client race conditions

It is currently possible for a client to send a response that doesn't match the
current server->client request(at the top of the stack). This commit fixes that
by delaying notifications to until the first `channel_send_call` invocation
returns.

Also remove the "call stack" size check, vim will already break if the call
stack goes too deep.

src/nvim/msgpack_rpc/channel.c

@@ -66,14 +66,23 @@ typedef struct {
   uint64_t request_id;
 } RequestEvent;
 
-#define RequestEventFreer(x)
+typedef struct {
-KMEMPOOL_INIT(RequestEventPool, RequestEvent, RequestEventFreer)
+  Channel *channel;
-kmempool_t(RequestEventPool) *request_event_pool = NULL;
+  String method;
+  Array args;
+} DelayedNotification;
 
+#define _noop(x)
+KMEMPOOL_INIT(RequestEventPool, RequestEvent, _noop)
+KLIST_INIT(DelayedNotification, DelayedNotification, _noop)
+
+static kmempool_t(RequestEventPool) *request_event_pool = NULL;
+static klist_t(DelayedNotification) *delayed_notifications = NULL;
 static uint64_t next_id = 1;
 static PMap(uint64_t) *channels = NULL;
 static PMap(cstr_t) *event_strings = NULL;
 static msgpack_sbuffer out_buffer;
+static size_t pending_requests = 0;
 
 #ifdef INCLUDE_GENERATED_DECLARATIONS
 # include "msgpack_rpc/channel.c.generated.h"
@@ -83,6 +92,7 @@ static msgpack_sbuffer out_buffer;
 void channel_init(void)
 {
   request_event_pool = kmp_init(RequestEventPool);
+  delayed_notifications = kl_init(DelayedNotification);
   channels = pmap_new(uint64_t)();
   event_strings = pmap_new(cstr_t)();
   msgpack_sbuffer_init(&out_buffer);
@@ -173,15 +183,27 @@ bool channel_send_event(uint64_t id, char *name, Array args)
 {
   Channel *channel = NULL;
 
-  if (id > 0) {
+  if (id && (!(channel = pmap_get(uint64_t)(channels, id))
-    if (!(channel = pmap_get(uint64_t)(channels, id)) || channel->closed) {
+            || channel->closed)) {
     api_free_array(args);
     return false;
   }
+
+  if (pending_requests) {
+    DelayedNotification p = {
+      .channel = channel,
+      .method = cstr_to_string(name),
+      .args = args
+    };
+    // Pending request, queue the notification for sending later
+    *kl_pushp(DelayedNotification, delayed_notifications) = p;
+  } else {
+    if (channel) {
       send_event(channel, name, args);
     } else {
       broadcast_event(name, args);
     }
+  }
 
   return true;
 }
@@ -206,16 +228,6 @@ Object channel_send_call(uint64_t id,
     return NIL;
   }
 
-  if (kv_size(channel->call_stack) > 20) {
-    // 20 stack depth is more than anyone should ever need for RPC calls
-    api_set_error(err,
-                  Exception,
-                  _("Channel %" PRIu64 " crossed maximum stack depth"),
-                  channel->id);
-    api_free_array(args);
-    return NIL;
-  }
-
   uint64_t request_id = channel->next_request_id++;
   // Send the msgpack-rpc request
   send_request(channel, request_id, method_name, args);
@@ -223,18 +235,24 @@ Object channel_send_call(uint64_t id,
   // Push the frame
   ChannelCallFrame frame = {request_id, false, false, NIL};
   kv_push(ChannelCallFrame *, channel->call_stack, &frame);
+  pending_requests++;
   event_poll_until(-1, frame.returned);
   (void)kv_pop(channel->call_stack);
+  pending_requests--;
 
   if (frame.errored) {
     api_set_error(err, Exception, "%s", frame.result.data.string.data);
     return NIL;
   }
 
-  if (channel->closed && !kv_size(channel->call_stack)) {
+  if (!kv_size(channel->call_stack) && channel->closed) {
     free_channel(channel);
   }
 
+  if (!pending_requests) {
+    send_delayed_notifications();
+  }
+
   return frame.result;
 }
 
@@ -678,6 +696,7 @@ static void complete_call(msgpack_object *obj, Channel *channel)
 
 static void call_set_error(Channel *channel, char *msg)
 {
+  ELOG("Msgpack-RPC error: %s", msg);
   for (size_t i = 0; i < kv_size(channel->call_stack); i++) {
     ChannelCallFrame *frame = kv_A(channel->call_stack, i);
     frame->returned = true;
@@ -727,6 +746,20 @@ static WBuffer *serialize_response(uint64_t channel_id,
   return rv;
 }
 
+static void send_delayed_notifications(void)
+{
+  DelayedNotification p;
+
+  while (kl_shift(DelayedNotification, delayed_notifications, &p) == 0) {
+    if (p.channel) {
+      send_event(p.channel, p.method.data, p.args);
+    } else {
+      broadcast_event(p.method.data, p.args);
+    }
+    free(p.method.data);
+  }
+}
+
 #if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL
 #define REQ "[request]      "
 #define RES "[response]     "
@@ -764,3 +797,4 @@ static void log_msg_close(FILE *f, msgpack_object msg)
   fclose(f);
 }
 #endif
+

test/functional/api/server_requests_spec.lua

@@ -2,8 +2,10 @@
 -- `rpcnotify`, to evaluate `rpcrequest` calls we need the client event loop to
 -- be running.
 local helpers = require('test.functional.helpers')
-local clear, nvim, eval, eq, run, stop = helpers.clear, helpers.nvim,
+local clear, nvim, eval = helpers.clear, helpers.nvim, helpers.eval
-      helpers.eval, helpers.eq, helpers.run, helpers.stop
+local eq, run, stop = helpers.eq, helpers.run, helpers.stop
+local restart = helpers.restart
+
 
 
 describe('server -> client', function()
@@ -13,6 +15,7 @@ describe('server -> client', function()
     clear()
     cid = nvim('get_api_info')[1]
   end)
+  teardown(restart)
 
   describe('simple call', function()
     it('works', function()
@@ -65,4 +68,53 @@ describe('server -> client', function()
       run(on_request, nil, on_setup)
     end)
   end)
+
+  describe('requests and notifications interleaved', function()
+    -- This tests that the following scenario won't happen:
+    --
+    -- server->client [request     ] (1)
+    -- client->server [request     ] (2) triggered by (1)
+    -- server->client [notification] (3) triggered by (2)
+    -- server->client [response    ] (4) response to (2)
+    -- client->server [request     ] (4) triggered by (3)
+    -- server->client [request     ] (5) triggered by (4)
+    -- client->server [response    ] (6) response to (1)
+    --
+    -- If the above scenario ever happens, the client connection will be closed
+    -- because (6) is returned after request (5) is sent, and nvim
+    -- only deals with one server->client request at a time. (In other words,
+    -- the client cannot send a response to a request that is not at the top
+    -- of nvim's request stack).
+    --
+    -- But above scenario shoudn't happen by the way notifications are dealt in
+    -- Nvim: they are only sent after there are no pending server->client
+    -- request(the request stack fully unwinds). So (3) is only sent after the
+    -- client returns (6).
+    it('works', function()
+      local expected = 300
+      local notified = 0
+      local function on_setup()
+        eq('notified!', eval('rpcrequest('..cid..', "notify")'))
+      end
+
+      local function on_request(method, args)
+        eq('notify', method)
+        eq(1, eval('rpcnotify('..cid..', "notification")'))
+        return 'notified!'
+      end
+
+      local function on_notification(method, args)
+        eq('notification', method)
+        if notified == expected then
+          stop()
+          return
+        end
+        notified = notified + 1
+        eq('notified', eval('rpcrequest('..cid..', "notify")'))
+      end
+
+      run(on_request, on_notification, on_setup)
+      eq(expected, notified)
+    end)
+  end)
 end)