test/run.sh hangs on OS X system python

[tsliwkan]

Trying to get this plugin working with the system python on OS X 10.11.4. Neovim is installed via homebrew with the version being NVIM 0.1.3-dev.

Running test/run.sh hangs with the last log message

[CRITICAL @ controller.py:safe_call:84] 2327 - Event Loop Thread is probably dead!

Currently being lazy so I modified run.sh to be

#!/bin/bash

set -e

TEST_DIR=$( /System/Library/Frameworks/Python.framework/Versions/2.7/bin/python -c "from os.path import realpath
print realpath(\"$(dirname "$0")\")" ) # resolve symlinks
cd "$TEST_DIR"
gcc -g -o ab ab.c
nvim -c 'e term:///System/Library/Frameworks/Python.framework/Versions/2.7/bin/python\ -i\ test.py'

To provide some more details I started by following http://blog.rplasil.name/2016/03/how-to-debug-neovim-python-remote-plugin.html.

The section in my init.vim for setting the python interpreter is

if has("unix")
    let s:uname = system("uname")
    if s:uname == "Darwin\n"
        let g:python_host_prog = '/System/Library/Frameworks/Python.framework/Versions/2.7/bin/python'
    endif
endif

I can echo that variable and it prints out just fine. I followed the instructions listed on that page for installing the neovim module. Launching that interpreter directly I get

Python 2.7.10 (default, Oct 23 2015, 19:19:21)
[GCC 4.2.1 Compatible Apple LLVM 7.0.0 (clang-700.0.59.5)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import lldb
>>> import neovim
>>>

This is what my system site-packages directory looks like

[/Library/Python/2.7/site-packages]
λ l
total 296
-rw-r--r--  1 root  wheel   119B 23 Oct 20:22 README
-rw-r--r--  1 root  wheel   434B 16 Apr 12:33 easy-install.pth
drwxr-xr-x  4 root  wheel   136B 16 Apr 11:26 futures-3.0.5-py2.7.egg
drwxr-xr-x  6 root  wheel   204B 16 Apr 11:26 greenlet-0.4.9-py2.7-macosx-10.11-intel.egg
-rw-r--r--  1 root  wheel   141K 16 Apr 11:26 msgpack_python-0.4.7-py2.7-macosx-10.11-intel.egg
drwxr-xr-x  4 root  wheel   136B 16 Apr 11:26 neovim-0.1.7-py2.7.egg
drwxr-xr-x  4 root  wheel   136B 16 Apr 11:26 trollius-2.1-py2.7.egg

I have PYTHONPATH set directly in my shell to

/Applications/Xcode.app/Contents/SharedFrameworks/LLDB.framework/Resources/Python

And I can run lldb -P which outputs

/Applications/Xcode.app/Contents/SharedFrameworks/LLDB.framework/Resources/Python

Note that I had to install the six module with

sudo /System/Library/Frameworks/Python.framework/Versions/2.7/bin/python -m easy_install six

otherwise lldb -P would complain about that missing module.

Finally, I couldn't see any discrepancies while installing the plugin and UpdateRemotePlugins seems to exit cleanly. Here is a screenshot of what test/run.sh looks like

[critiqjo]

I'm not so sure what's going wrong... Try increasing the delay to 2 seconds here and rerun the tests.

If that doesn't work, add this line:

self.logger.info(method.__name__, args)

below this line, try reproducing this error, and give me the whole log as text.

[tsliwkan]

Added delay as 2 and added the logger method. I also modified my $PATH so python2 is will be run from the system directory.

From the terminal buffer

File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading
.py", line 810, in __bootstrap_inner
    self.run
  File "/Users/tsliwkan/config/nvim/plugged/lldb.nvim/rplugin/python/lldb_nvim/controlle
r.py", line 286, in run
    out += self._process.GetSTDERR(256)
TypeError: unsupported operand type(s) for +=: 'NoneType' and 'NoneType'

Traceback (most recent call last):
  File "test.py", line 40, in <module>
    iface._exec('continue')
  File "/Users/tsliwkan/config/nvim/plugged/lldb.nvim/rplugin/python/lldb_nvim/__init__.
py", line 41, in _exec
    self.ctrl.safe_execute(args)
  File "/Users/tsliwkan/config/nvim/plugged/lldb.nvim/rplugin/python/lldb_nvim/controlle
r.py", line 93, in safe_execute
    self.safe_call(self.exec_command, [cmd])
  File "/Users/tsliwkan/config/nvim/plugged/lldb.nvim/rplugin/python/lldb_nvim/controlle
r.py", line 86, in safe_call
    raise EventLoopError("Dead event loop!")
EventLoopError: Dead event loop!
Debugger terminated! If you see no errors, everything's cool!

and from test.log

2016-04-16 14:40:13,647 [INFO @ controller.py:safe_call:69] 3032 - handle
2016-04-16 14:40:13,647 [INFO @ controller.py:run:275] 3032 - Calling handle with ['load', 'lldb-nvim.json']
2016-04-16 14:40:13,649 [INFO @ vim_x.py:call:19] 3032 - ('lldb#layout#init_buffers',)
2016-04-16 14:40:15,648 [INFO @ controller.py:safe_call:69] 3032 - mode_setup
2016-04-16 14:40:15,648 [INFO @ controller.py:run:275] 3032 - Calling mode_setup with ['debug']
2016-04-16 14:40:16,265 [INFO @ vim_x.py:call:19] 3032 - ('bufnr', '/Users/tsliwkan/config/nvim/plugged/lldb.nvim/test/ab.c', 1)
2016-04-16 14:40:16,265 [INFO @ vim_x.py:call:19] 3032 - ('setbufvar', 2, '&bl', 1)
2016-04-16 14:40:16,266 [INFO @ vim_x.py:call:19] 3032 - ('bufnr', '/Users/tsliwkan/config/nvim/plugged/lldb.nvim/test/ab.c', 1)
2016-04-16 14:40:16,266 [INFO @ vim_x.py:call:19] 3032 - ('setbufvar', 2, '&bl', 1)
2016-04-16 14:40:16,266 [INFO @ vim_x.py:call:19] 3032 - ('bufnr', '/Users/tsliwkan/config/nvim/plugged/lldb.nvim/test/ab.c', 1)
2016-04-16 14:40:16,267 [INFO @ vim_x.py:call:19] 3032 - ('setbufvar', 2, '&bl', 1)
2016-04-16 14:40:19,652 [INFO @ controller.py:safe_call:69] 3032 - exec_command
2016-04-16 14:40:21,654 [INFO @ controller.py:safe_call:69] 3032 - put_stdin
2016-04-16 14:40:23,656 [INFO @ controller.py:safe_call:69] 3032 - exec_command
2016-04-16 14:40:23,657 [CRITICAL @ controller.py:safe_call:85] 3032 - Event loop thread is probably dead!

[tsliwkan]

Oops, the above test.log output is from

self.logger.info(method.__name__)

if I add the args argument I get

Note: `:LL-` commands are not bound with this test instance
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/_
_init__.py", line 859, in emit
    msg = self.format(record)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/_
_init__.py", line 732, in format
    return fmt.format(record)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/_
_init__.py", line 471, in format
    record.message = record.getMessage()
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/_
_init__.py", line 335, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file controller.py, line 69

[critiqjo]

Ah! It was not the problem with delay. GetSTDOUT here is returning None. I don't know why it does... Try inserting this condition in-between those lines:

out = self._process.GetSTDOUT(256)
if out is None:
  break
out += self._process.GetSTDERR(256)

And check if you're able to work with the plugin, and the process stdout is getting printed...

[critiqjo]

Oops, the above test.log output is from

Ya, that was a mistake from my part. Remove that line... (I forgot that str(args) was required)

[tsliwkan]

OK. I think this is working now. I changed controller.py a little bit more from your suggestion, the block in question now looks like

out = ''
stdout = self._process.GetSTDOUT(256)
if stdout is not None:
  out += stdout
stderr = self._process.GetSTDERR(256)
if stderr is not None:
  out += stderr 
if len(out) == 0:
  break

as I was still getting an error with += on str and None types from self._process.GetSTDERR(256). test/run.sh passed now, the term window outputs

Note: `:LL-` commands are not bound with this test instance
Debugger terminated! If you see no errors, everything's cool!
>>>

I also fired up my own "Hello world" in C, running the commands

:LLsession new
:LLmode debug
:LL continue

and the process exited with code 0!

[critiqjo]

Is "Hello world" actually printed in the log buffer? I'm guessing the debugger is not getting any process outputs now.

[tsliwkan]

In the pane [lldb]logs

(lldb) target create a.out
Current executable set to 'a.out' (x86_64).
(lldb) breakpoint set -n main
Breakpoint 1: where = a.out`main, address = 0x0000000100000f50
(lldb) process launch
Process 3295 launched: '/Users/tsliwkan/development/a.out' (x86_64)
(lldb) continue
Process 3295 resuming
Hello, world!

[critiqjo]

Okay, great!! I'll push that fix soon...

[tsliwkan]

Cheers! Thanks for the prompt replies. Also, thanks for your work on this plugin, it looks super slick.