API: nvim_buf_attach not returning

[eidheim]

When testing the new buffer API functions through nvim --embed, I noticed that nvim_buf_attach never returns, but an event is fired. Also, when calling for instance nvim_buf_set_lines, it often returns, but not always.

[justinmk]

What does "no return" mean? Is it blocking ? What client are you using. Provide complete, exact steps, not a description.

[eidheim]

You probably don't want to look at my C++ code, but here is how you can reproduce the issue using node:

const { spawn } = require("child_process");
const msgpack = require("msgpack-lite");

const nvim = spawn("nvim", ["--embed"]);

nvim.stdout.on("data", data => {
  console.log(msgpack.decode(Buffer.from(data)));
});

nvim.stdin.write(msgpack.encode([0, 0, "nvim_buf_attach", [0, false, {}]]));

Results in:

[ 2,
  'nvim_buf_changedtick_event',
  [ ExtBuffer { buffer: <Buffer 01>, type: 0 }, 2 ] ]

nvim_buf_attach yields no return package (https://github.com/neovim/neovim/blob/master/runtime/doc/api.txt#L865).

However, nvim_ui_attach works as expected:

const { spawn } = require("child_process");
const msgpack = require("msgpack-lite");

const nvim = spawn("nvim", ["--embed"]);

nvim.stdout.on("data", data => {
  // console.log(data);
  console.log(msgpack.decode(data));
});

nvim.stdin.write(msgpack.encode([0, 0, "nvim_ui_attach", [1, 1, {}]]));

[ 2,
  'redraw',
  [ [ 'option_set',
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array] ],
    [ 'default_colors_set', [Array] ],
    [ 'update_fg', [Array] ],
    [ 'update_bg', [Array] ],
    [ 'update_sp', [Array] ],
    [ 'resize', [Array] ],
    [ 'clear', [] ],
    [ 'cursor_goto', [Array] ],
    [ 'highlight_set', [Array] ],
    [ 'put',
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array],
      [Array] ],
    [ 'cursor_goto', [Array] ] ] ]
[ 1, 0, null, null ]

The last line above ([ 1, 0, null, null ]) is the return package for nvim_ui_attach.

[justinmk]

Can't reproduce using the python client.

>>> import neovim
>>> n = neovim.attach('socket', path='/tmp/nvimR9w38H/0')
>>> n.request('nvim_buf_attach', 0, False, {})
True
>>> n2 = neovim.attach('child', argv=['nvim', '-u','NONE','--embed'])
>>> n2.request('nvim_buf_attach', 0, False, {})
True

[justinmk]

If I repeat the call then I see a response.

nvim.stdin.write(msgpack.encode([0, 0, "nvim_buf_attach", [0, false, {}]]));  
true                                                                        
>                                                                             
> stdout:                                                                   
[ 1, 0, null, true ]                                   

Maybe it's related to buffering. But why does it only happen on the first call? (A: Because nvim_buf_changedtick_event doesn't get sent on the subsequent calls.) And why doesn't it happen in the python-client? (A: python client correctly handles notifications even if a request is waiting on a response.)

If I build nvim with DEBUG-level logging:

rm -rf build
make CMAKE_EXTRA_FLAGS="-DMIN_LOG_LEVEL=0"

then use that build from javascript:

const { spawn } = require("child_process");
const msgpack = require("msgpack-lite");
const nvim = spawn("./build/bin/nvim", ["-u", "NONE", "-i", "NONE", "-n", "--embed"], {env: {NVIM_LOG_FILE: 'log'}});
nvim.stdout.on("data", data => {                                                                                                                          
  console.log('stdout: ');                                                                                                                                
  console.log(msgpack.decode(Buffer.from(data)));                                                                                                         
});                                                                                                                                                       
nvim.stdin.write(msgpack.encode([0, 0, "nvim_buf_attach", [0, false, {}]]));

the Nvim log shows that the response was written to the channel:

tail -F log

2018/06/26 09:12:25 DEBUG 31981 receive_msgpack:226: ch 1: parsing 23 bytes from msgpack Stream: 0x7f02ce49a820
2018/06/26 09:12:25 DEBUG 31981 log_client_msg:729: RPC <-ch 1: [request]  [0, 0, "nvim_buf_attach", [0, false, {}]]
2018/06/26 09:12:25 DEBUG 31981 UI: cursor_goto
2018/06/26 09:12:25 DEBUG 31981 UI: flush
2018/06/26 09:12:25 DEBUG 31981 log_server_msg:692: RPC ->ch 1: [notify]   [2, "nvim_buf_changedtick_event", [(ext: 0)"\x01", 2]]
2018/06/26 09:12:25 DEBUG 31981 log_server_msg:692: RPC ->ch 1: [response] [1, 0, nil, true]

so the problem (if any) doesn't seem to be at the Nvim RPC level.

Note that the notification is written before the response.
@billyvg is the node-client prepared to handle notifications in the middle of a request-response? ref: #6544

[eidheim]

In case it helps, here is my C++ source where I test the nvim API: https://gitlab.com/eidheim/neovim-embed-test. Note that I added a second delay before calling nvim_buf_attach, and then I get a result back around 50% of the time. Clone the repository with --recursive to get the submodule I use.

[justinmk]

@eidheim Is your client prepared to handle notifications while waiting on a response? See my previous comment.

[eidheim]

Yes, the C++ client handles notifications while waiting for a response.

[justinmk]

Can you build with DMIN_LOG_LEVEL=0 as described above, and compare the time of the log message?

[billyvg]

@justinmk yes the node client can handle notifications in between request/response, none of the examples are using the node client though.

note that node-client currently wraps the call to nvim_buf_attach, and ends up discarding the the response when it initially makes the request. node-client will only allow you to attach to a buffer (using nvim_buf_attach), once.

[justinmk]

Oops, right. I started with the node client locally, then combined too many thoughts...

[billyvg]

Also fwiw, when building neovim from source (from latest master), the node snippet from @justinmk produces this:

node-client git/master*
❯ node test.js
stdout:
[ 2,
  'nvim_buf_changedtick_event',
  [ ExtBuffer { buffer: <Buffer 01>, type: 0 }, 2 ] ]
stdout:
[ 1, 0, null, true ]

[eidheim]

I tried the latest master and can confirm that both the node client and C++ client works. That is, the C++ client works if I remove this line: https://gitlab.com/eidheim/neovim-embed-test/blob/master/main.cpp#L60, so there is sadly still some issue here I think.

[justinmk]

@eidheim what nvim version were you testing before ...? Nothing changed in RPC or channel implementation since 0.3.0 was released.

the C++ client works if I remove this line: https://gitlab.com/eidheim/neovim-embed-test/blob/master/main.cpp#L60, so there is sadly still some issue here I think.

Why would this point to an issue with Nvim? Nvim writes to a buffer. sleep() tickles the OS scheduler. Nvim is single threaded. That c++ client is multithreaded ...

[eidheim]

I used nvim 0.3.0 on MacOS and Arch Linux. To test latest master, I installed neovim-git through Arch Linux AUR using yaourt.

The only thing the sleep is doing, is wait a second before writing the nvim_buf_attach msgpack to the nvim process. The problem lies in the new buffer functions I would think, because if I wait a second before calling nvim_ui_attach instead, it works as expected.

[eidheim]

The problem can be reproduced using node:

const { spawn } = require("child_process");
const msgpack = require("msgpack-lite");

const nvim = spawn("nvim", ["--embed"]);

nvim.stdout.on("data", data => {
  console.log(msgpack.decode(data));
});

setTimeout(() => {
  nvim.stdin.write(msgpack.encode([0, 0, "nvim_buf_attach", [0, false, {}]]));
}, 1000);

Outputs:

[ 2,
  'nvim_buf_changedtick_event',
  [ ExtBuffer { buffer: <Buffer 01>, type: 0 }, 2 ] ]

That is without the result package.

[justinmk]

Couldn't that be a race in nvim.start()?

You also mentioned:

Also, when calling for instance nvim_buf_set_lines, it often returns, but not always.

This hasn't been reported before. We have thousands of RPC tests that depend on the basic functionality of an RPC response.

[eidheim]

The problem with nvim_buf_set_lines could be related to the issue where a delayed nvim_buf_attach message also does not yield a return package. Please see the node example in my previous post.

[KillTheMule]

I can't follow here, but let me just throw in that I've written benchmarks in rust that embed a neovim instance, and I do not have to wait for the spawn or something like this. I've also not noticed a reply missing (same goes for the lua tests I've written).

[billyvg]

It's working for me:

[justinmk]

In #8663 @roflcopter4 mentioned that they created another custom nvim client in C. @roflcopter4 can you confirm whether you also observe the behavior in this issue? Specifically, does the (boolean) return value of a RPC call to nvim_buf_attach sometimes not get returned?

[roflcopter4]

The boolean value being the 6th argument, right? I haven't noticed any kind of problem with that. My hacky "client" is too undeveloped right now to bother distinguishing between expected replies and notifications, so I made it multi-threaded and opened a socket for each thread. One socket, one request, one reply. Neovim always returns promptly, to the correct socket, as expected.

[justinmk]

@eidheim I added a test in https://github.com/neovim/neovim/pull/8672/files#diff-d68045ff8f987ecf323e339fe76df7cdR744 which I think matches the semantics of the steps in #8634 (comment) .

[dhleong]

For what it's worth I'm also experiencing this issue in my Kotlin project, and can also reproduce it via a node script like those linked above:

const { spawn } = require("child_process");
const msgpack = require("msgpack-lite");

console.log("spawning...");
const nvim = spawn("nvim", ["-u", "NONE", "--embed"]);

nvim.stderr.on("data", data => {
    console.log("ERR", data);
});
nvim.stdout.on("data", data => {
    console.log('stdout: ');
    console.log(msgpack.decode(Buffer.from(data)));
});

nvim.stdin.write(msgpack.encode([0, 0, "nvim_buf_attach", [0, false, {}]]));
setTimeout(() => {
    console.log("timeout");
    process.exit(1);
}, 1500);

With nvim 0.3.1 I get:

nvim-test  ./buf-attach.js
spawning...
stdout: 
[ 2,
  'nvim_buf_changedtick_event',
  [ ExtBuffer { buffer: <Buffer 01>, type: 0 }, 2 ] ]
timeout

With the latest HEAD (via brew install neovim --HEAD) I do get a response, but it returns false. If I wait to issue nvim_buf_attach until after editing a file (nvim.stdin.write(msgpack.encode([0, 0, "nvim_command", ["e! asdf"]]));) then has a similar output to the 0.3.1 version—no response to nvim_buf_attach, just the _changedtick_event (and of course the response to nvim_command).

[dhleong]

Similarly, nvim_buf_detach seems to not send a Response (other than the nvim_buf_detach_event):

#!/usr/bin/env node

const { spawn } = require("child_process");
const msgpack = require("msgpack-lite");

console.log("spawning...");
const nvim = spawn("nvim", ["-u", "NONE", "--embed"]);

nvim.stderr.on("data", data => {
    console.log("ERR", data);
});
nvim.stdout.on("data", data => {
    console.log('stdout: ');
    console.log(msgpack.decode(Buffer.from(data)));
});

nvim.stdin.write(msgpack.encode([0, 0, "nvim_buf_attach", [0, false, {}]]));

setTimeout(() => {
    nvim.stdin.write(msgpack.encode([0, 1, "nvim_buf_detach", [0]]));
}, 1000);

setTimeout(() => {
    console.log("timeout");
    process.exit(1);
}, 2500);

results in:

nvim-test dhleong$  ./buf-attach.js
spawning...
stdout: 
[ 2,
  'nvim_buf_changedtick_event',
  [ ExtBuffer { buffer: <Buffer 01>, type: 0 }, 2 ] ]
stdout: 
[ 2,
  'nvim_buf_detach_event',
  [ ExtBuffer { buffer: <Buffer 01>, type: 0 } ] ]
timeout

With nvim 0.3.1