Repository: neovim
Issue: logging: invalid msgpack-rpc string
Labels: bug,test,channels-rpc

Since spell_spec.lua was added, this occasionally fails on travis macOS. We need more visibility into "invalid msgpack-rpc string", perhaps we should keep the full request and if this type of failure is detected, dump the request contents.

There are multiple projects involved, and currently I'm not sure where the `invalid msgpack-rpc string` comes from:

- https://github.com/neovim/lua-client
- https://github.com/libmpack/libmpack
- neovim itself (and its test framework in  `test/functional/*`)


```
[32m[2m[----------][0m[0m Running tests from [36m/Users/travis/build/neovim/neovim/test/functional/ui/spell_spec.lua[0m
[32m[2m[ RUN      ][0m[0m 'spell' joins long lines #7937: -- Output to stderr:
Uncaught Error: .../nvim-deps/usr/share/lua/5.1/nvim/msgpack_rpc_stream.lua:84: invalid msgpack-rpc string

stack traceback:
	[C]: in function 'receive'
	.../nvim-deps/usr/share/lua/5.1/nvim/msgpack_rpc_stream.lua:84: in function 'cb'
	...vim-deps/usr/share/lua/5.1/nvim/child_process_stream.lua:43: in function <...vim-deps/usr/share/lua/5.1/nvim/child_process_stream.lua:39>
	[C]: in function 'run'
	/Users/travis/nvim-deps/usr/share/lua/5.1/nvim/session.lua:179: in function '_run'
	/Users/travis/nvim-deps/usr/share/lua/5.1/nvim/session.lua:126: in function 'run'
	test/functional/helpers.lua:192: in function 'run'
	test/functional/ui/screen.lua:286: in function 'wait'
	test/functional/ui/screen.lua:221: in function 'expect'
	...is/build/neovim/neovim/test/functional/ui/spell_spec.lua:38: in function <...is/build/neovim/neovim/test/functional/ui/spell_spec.lua:27>
	...
	/Users/travis/nvim-deps/usr/share/lua/5.1/busted/block.lua:155: in function 'execute'
	/Users/travis/nvim-deps/usr/share/lua/5.1/busted/init.lua:7: in function 'executor'
	/Users/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:312: in function </Users/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:312>
	[C]: in function 'xpcall'
	/Users/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:178: in function 'safe'
	/Users/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:312: in function 'execute'
	...rs/travis/nvim-deps/usr/share/lua/5.1/busted/execute.lua:58: in function 'execute'
	/Users/travis/nvim-deps/usr/share/lua/5.1/busted/runner.lua:174: in function </Users/travis/nvim-deps/usr/share/lua/5.1/busted/runner.lua:11>
	...deps/usr/lib/luarocks/rocks/busted/2.0.rc12-1/bin/busted:3: in main chunk
	[C]: at 0x0100001010

CMake Error at /Users/travis/build/neovim/neovim/cmake/RunTests.cmake:53 (message):

  Running functional tests failed with error: 1.
```

"trailing data in msgpack string" seen in https://github.com/neovim/neovim/pull/8304:

```
[32m[2m[ RUN      ][0m[0m nvim_ui_attach() handles very large width/height #2180: -- Output to stderr:
Uncaught Error: ...m-deps/usr/share/lua/5.1/nvim/msgpack_rpc_stream.lua:53: trailing data in msgpack string
stack traceback:
	[C]: in function 'unpack'
	...m-deps/usr/share/lua/5.1/nvim/msgpack_rpc_stream.lua:53: in function <...m-deps/usr/share/lua/5.1/nvim/msgpack_rpc_stream.lua:53>
	[C]: in function 'receive'
	...m-deps/usr/share/lua/5.1/nvim/msgpack_rpc_stream.lua:84: in function 'cb'
	...deps/usr/share/lua/5.1/nvim/child_process_stream.lua:43: in function <...deps/usr/share/lua/5.1/nvim/child_process_stream.lua:39>
	[C]: in function 'run'
	.../travis/nvim-deps/usr/share/lua/5.1/nvim/session.lua:179: in function '_run'
	.../travis/nvim-deps/usr/share/lua/5.1/nvim/session.lua:165: in function '_blocking_request'
	.../travis/nvim-deps/usr/share/lua/5.1/nvim/session.lua:86: in function 'request'
	test/functional/helpers.lua:90: in function <test/functional/helpers.lua:89>
	...
	.../travis/nvim-deps/usr/share/lua/5.1/busted/block.lua:155: in function 'execute'
	...e/travis/nvim-deps/usr/share/lua/5.1/busted/init.lua:7: in function 'executor'
	...e/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:312: in function <...e/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:312>
	[C]: in function 'xpcall'
	...e/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:178: in function 'safe'
	...e/travis/nvim-deps/usr/share/lua/5.1/busted/core.lua:312: in function 'execute'
	...ravis/nvim-deps/usr/share/lua/5.1/busted/execute.lua:58: in function 'execute'
	...travis/nvim-deps/usr/share/lua/5.1/busted/runner.lua:174: in function <...travis/nvim-deps/usr/share/lua/5.1/busted/runner.lua:11>
	.../usr/lib/luarocks/rocks/busted/2.0.rc12-1/bin/busted:3: in main chunk
	[C]: ?

CMake Error at /home/travis/build/neovim/neovim/cmake/RunTests.cmake:53 (message):
  Running functional tests failed with error: 1.
```