Deoplete.nvim: Completion menu show up time is long if a source is slow

Created on 8 Feb 2018  路  32Comments  路  Source: Shougo/deoplete.nvim

Warning: I will close the issue without the minimal init.vim and the reproduction instructions.

Problems summary

I compared deoplete with ncm.
In ncm, if a source is slow, it will not impact the completion menu show up time.
But in ncm, if a source is slow, it will impact the completion menu show up time.

Expected

If some source is slow, the faster source should show in completion menu first.

Environment Information

  • deoplete version(SHA1):
    c145a7fea45850f5e19151f9748a0dc8e8e92329

  • OS:
    windows 10

  • neovim/Vim version:
    NVIM 0.2.2

  • :checkhealth or :CheckHealth result(neovim only):

health#deoplete#check
========================================================================
## deoplete.nvim
  - OK: has("nvim") was successful
  - OK: has("python3") was successful
  - INFO: If you're still having problems, try the following commands:
    $ export NVIM_PYTHON_LOG_FILE=/tmp/log
    $ export NVIM_PYTHON_LOG_LEVEL=DEBUG
    $ nvim
    $ cat /tmp/log_{PID}
    and then create an issue on github

health#nvim#check
========================================================================
## Configuration
  - OK: no issues found

## Performance
  - OK: Build type: RelWithDebInfo

## Remote Plugins
  - OK: Up to date

health#provider#check
========================================================================
## Clipboard (optional)
  - OK: Clipboard tool found: win32yank

## Python 2 provider (optional)
  - WARNING: No Python interpreter was found with the neovim module.  Using the first available for diagnostics.
  - WARNING: provider/pythonx: Could not load Python 2:
    python2 not found in search path or not executable.
    python2.7 not found in search path or not executable.
    python2.6 not found in search path or not executable.
    C:\Users\jia.sui\AppData\Local\Programs\Python\Python36\python is Python 3.6 and cannot provide Python 2.
  - ERROR: Python provider error
    - ADVICE:
      - provider/pythonx: Could not load Python 2:
          python2 not found in search path or not executable.
          python2.7 not found in search path or not executable.
          python2.6 not found in search path or not executable.
          C:\Users\jia.sui\AppData\Local\Programs\Python\Python36\python is Python 3.6 and cannot provide Python 2.
  - INFO: Executable: Not found

## Python 3 provider (optional)
  - INFO: Using: g:python3_host_prog = "C:/Users/jia.sui/AppData/Local/Programs/Python/Python36/python.exe"
  - INFO: Executable: C:/Users/jia.sui/AppData/Local/Programs/Python/Python36/python.exe
  - INFO: Python3 version: 3.6.4
  - INFO: python.exe-neovim version: 0.2.1
  - OK: Latest python.exe-neovim is installed: 0.2.1

## Ruby provider (optional)
  - WARNING: `ruby` and `gem` must be in $PATH.
    - ADVICE:
      - Install Ruby and verify that `ruby` and `gem` commands work.

## Node provider (optional)
  - INFO: Node: v8.9.0
  - WARNING: Missing "neovim" npm package.
    - ADVICE:
      - Run in shell: npm install -g neovim
      - Is the npm bin directory in $PATH?

Provide a minimal init.vim/vimrc with less than 50 lines (Required!)

let s:rc_path = fnamemodify(expand('<sfile>'), ':h')

let s:vimplug = expand(s:rc_path . '/autoload')

if empty(glob(s:vimplug . '/plug.vim'))
  execute '!git clone --depth=1 https://github.com/junegunn/vim-plug' s:vimplug
  augroup vimrc
    autocmd VimEnter * PlugInstall
  augroup END
endif

call plug#begin(s:rc_path . '/plugged')

"Completion
Plug 'Shougo/deoplete.nvim', { 'do': ':UpdateRemotePlugins' }

call plug#end()

"deoplete.nvim
if (has('nvim') || v:version >= 800) && has('python3')
  let g:deoplete#enable_at_startup = 1
  let g:deoplete#num_processes = 20
endif

The reproduce ways from neovim/Vim starting (Required!)

  1. Add a time.sleep(10) in gather_candidates() tag.py

    diff --git a/rplugin/python3/deoplete/source/tag.py b/rplugin/python3/deoplete/source/tag.py
index 1dcec7f..7a32695 100644
--- a/rplugin/python3/deoplete/source/tag.py
+++ b/rplugin/python3/deoplete/source/tag.py
@@ -33,6 +33,8 @@ class Source(Base):
     self._make_cache(context)

 def gather_candidates(self, context):
+        import time
+        time.sleep(10)
     self._make_cache(context)
     candidates = []
     for c in self._cache.values():
  2. Add
  3. Open any files, then type something
  4. The completion window will show up after 10s

Screen shot (if possible)

deoplete

Upload the log file

deoplete.log

bug performance
Source
picture jsfaint

All 32 comments

Reproduced.

Shougo picture Shougo on 8 Feb 2018 
diff --git a/rplugin/python3/deoplete/parent.py b/rplugin/python3/deoplete/parent.py
index 97cb510..b03ea7d 100644
--- a/rplugin/python3/deoplete/parent.py
+++ b/rplugin/python3/deoplete/parent.py
@@ -88,5 +88,5 @@ class Parent(logger.LoggingMixin):
         return queue_id

     def _get(self, queue_id):
-        return [x for x in self._proc.communicate(40)
+        return [x for x in self._proc.communicate(0.02)
                 if x['queue_id'] == queue_id]

Here is the patch for it.

Shougo picture Shougo on 8 Feb 2018

Thanks for the quick response, but it's a pity, this patch not works for me.

Patch on deoplete

diff --git a/rplugin/python3/deoplete/parent.py b/rplugin/python3/deoplete/parent.py
index 97cb510..b03ea7d 100644
--- a/rplugin/python3/deoplete/parent.py
+++ b/rplugin/python3/deoplete/parent.py
@@ -88,5 +88,5 @@ class Parent(logger.LoggingMixin):
         return queue_id

     def _get(self, queue_id):
-        return [x for x in self._proc.communicate(40)
+        return [x for x in self._proc.communicate(0.02)
                 if x['queue_id'] == queue_id]
diff --git a/rplugin/python3/deoplete/source/tag.py b/rplugin/python3/deoplete/source/tag.py
index 1dcec7f..7a32695 100644
--- a/rplugin/python3/deoplete/source/tag.py
+++ b/rplugin/python3/deoplete/source/tag.py
@@ -33,6 +33,8 @@ class Source(Base):
         self._make_cache(context)

     def gather_candidates(self, context):
+        import time
+        time.sleep(10)
         self._make_cache(context)
         candidates = []
         for c in self._cache.values():

Here is the new log file
deoplete.log

jsfaint picture jsfaint on 8 Feb 2018

It works for me.
But it does not work sometimes.
I don't know why.

Shougo picture Shougo on 8 Feb 2018

http://drmingdrmer.github.io/tech/programming/2017/11/20/python-concurrent-popen.html

Shougo picture Shougo on 9 Feb 2018

I should use concurrent.futures.ProcessPoolExecutor() instead.
I will try it later.

Shougo picture Shougo on 9 Feb 2018
👍1

I have tested concurrent.futures.ProcessPoolExecutor().
It is better than before, but it cannot fix the problem completely.
It needs async io support.

https://github.com/neovim/python-client/pull/294

Shougo picture Shougo on 14 Feb 2018 
diff --git a/rplugin/python3/deoplete/deoplete.py b/rplugin/python3/deoplete/deoplete.py
index 0ce7e54..75f57fb 100644
--- a/rplugin/python3/deoplete/deoplete.py
+++ b/rplugin/python3/deoplete/deoplete.py
@@ -4,6 +4,8 @@
 # License: MIT license
 # ============================================================================

+from concurrent.futures import ThreadPoolExecutor
+
 from deoplete import logger
 from deoplete.parent import Parent
 from deoplete.util import (error_tb, find_rplugins)
@@ -38,8 +40,9 @@ class Deoplete(logger.LoggingMixin):
         context['rpc'] = 'deoplete_on_event'

         # Init processes
+        self._executor = ThreadPoolExecutor(max_workers=4)
         for n in range(0, self._max_parents):
-            self._parents.append(Parent(vim, context))
+            self._parents.append(Parent(vim, context, self._executor))
         if self._vim.vars['deoplete#_logging']:
             for parent in self._parents:
                 parent.enable_logging()
diff --git a/rplugin/python3/deoplete/parent.py b/rplugin/python3/deoplete/parent.py
index 6dba494..a97e470 100644
--- a/rplugin/python3/deoplete/parent.py
+++ b/rplugin/python3/deoplete/parent.py
@@ -13,7 +13,7 @@ from deoplete.process import Process

 class Parent(logger.LoggingMixin):

-    def __init__(self, vim, context):
+    def __init__(self, vim, context, executor):
         self.name = 'parent'

         self._vim = vim
@@ -21,7 +21,7 @@ class Parent(logger.LoggingMixin):
         self._child = None
         self._queue_id = ''
         self._prev_pos = []
-        self._start_process(context)
+        self._start_process(context, executor)

     def enable_logging(self):
         self._put('enable_logging', [])
@@ -68,14 +68,14 @@ class Parent(logger.LoggingMixin):
         if context['event'] == 'VimLeavePre':
             self._stop_process()

-    def _start_process(self, context):
+    def _start_process(self, context, executor):
         if self._vim.vars['deoplete#num_processes'] > 1:
             # Parallel
             python3 = self._vim.vars.get('python3_host_prog', 'python3')
             self._proc = Process(
                 [python3, context['dp_main'],
                  self._vim.vars['deoplete#_serveraddr']],
-                context, context['cwd'])
+                context, context['cwd'], executor)
         else:
             # Serial
             from deoplete.child import Child
diff --git a/rplugin/python3/deoplete/process.py b/rplugin/python3/deoplete/process.py
index 728f7fe..5bfc657 100644
--- a/rplugin/python3/deoplete/process.py
+++ b/rplugin/python3/deoplete/process.py
@@ -7,13 +7,12 @@
 import subprocess
 import os
 import msgpack
-from threading import Thread
 from queue import Queue
 from time import time, sleep


 class Process(object):
-    def __init__(self, commands, context, cwd):
+    def __init__(self, commands, context, cwd, executor):
         startupinfo = None
         if os.name == 'nt':
             startupinfo = subprocess.STARTUPINFO()
@@ -33,18 +32,16 @@ class Process(object):
             encoding='utf-8',
             unicode_errors='surrogateescape')
         self._queue_out = Queue()
-        self._thread = Thread(target=self.enqueue_output)
-        self._thread.start()
+        self._future = executor.submit(self.enqueue_output)

     def kill(self):
         if not self._proc:
             return
+        self._future.cancel()
         self._proc.kill()
         self._proc.wait()
         self._proc = None
         self._queue_out = None
-        self._thread.join(1.0)
-        self._thread = None

     def enqueue_output(self):
         while self._proc:
diff --git a/rplugin/python3/deoplete/source/tag.py b/rplugin/python3/deoplete/source/tag.py
index b407d03..88f2f9b 100644
--- a/rplugin/python3/deoplete/source/tag.py
+++ b/rplugin/python3/deoplete/source/tag.py
@@ -33,6 +33,8 @@ class Source(Base):
         self._make_cache(context)

     def gather_candidates(self, context):
+        import time
+        time.sleep(10)
         self._make_cache(context)
         candidates = []
         for c in self._cache.values():

You can test the patch.

Shougo picture Shougo on 14 Feb 2018

@Shougo Thanks for your effort.
I'm just curious that how did ncm handle this condition?
Can you introduce something please? @roxma 馃槃

jsfaint picture jsfaint on 14 Feb 2018

I'm just curious that how did ncm handle this condition?

nvim-completion-manager uses neovim event loop instead.
deoplete does not use it.

Shougo picture Shougo on 14 Feb 2018

I tried the patch on windows, it doesn't work on most time.
Here is the log on windows
deoplete.log

jsfaint picture jsfaint on 14 Feb 2018

It is better than before, but it cannot fix the problem completely.

Shougo picture Shougo on 14 Feb 2018

Oh, concurrent.future version makes Vim exiting time will be slowly.
So I cannot merge the patch.

Shougo picture Shougo on 15 Feb 2018

I will test https://github.com/neovim/python-client/pull/294 and add support it later.

Shougo picture Shougo on 15 Feb 2018

https://github.com/neovim/python-client/pull/294 is merged.
I will add the support later.

Shougo picture Shougo on 2 Mar 2018
👍1

@https://github.com/neovim/python-client/pull/294#issuecomment-369866578

I have tested it, but it does not work

Shougo picture Shougo on 6 Mar 2018
👍1

@Shougo Should I test it now? or maybe later

jsfaint picture jsfaint on 6 Mar 2018

I test now...
But some problems are available.

Result: No magic.

Shougo picture Shougo on 6 Mar 2018

@Shougo I'm sorry to hear that.

jsfaint picture jsfaint on 6 Mar 2018

The candidates filtering does not work. I don't know why. It is very confusing problem.

I have fixed the problem.

Shougo picture Shougo on 6 Mar 2018

Add a time.sleep(10) in gather_candidates() tag.py

I have tested it in asyncio patch.
It works for me.

Shougo picture Shougo on 6 Mar 2018

https://gist.github.com/Shougo/b1292a539dcf7058c5e22b253fd46339

Note: It may not work in Windows environment.

I think it is the faster implementation.
Because, it does not have any sleep.

Shougo picture Shougo on 6 Mar 2018

The patch in gist was fail to apply on deoplete master

$ git apply asyncio.diff
error: patch fragment without header at line 284: @@ -82,7 +85,8 @@ class Deoplete(logger.LoggingMixin):
jsfaint picture jsfaint on 6 Mar 2018

You should use patch -p1 instead.

Shougo picture Shougo on 6 Mar 2018

I tried this patch on linux, it works for me.
But it looks the new version of python-neovim fail to work on Windows.
There are many errors when run :UpdateRemotePlugins on Windows

jsfaint picture jsfaint on 6 Mar 2018

But it looks the new version of python-neovim fail to work on Windows.
There are many errors when run :UpdateRemotePlugins on Windows

Yes.
It is python-neovim problem.

https://github.com/neovim/python-client/pull/307

Shougo picture Shougo on 6 Mar 2018

https://github.com/neovim/python-client/issues/306

Shougo picture Shougo on 6 Mar 2018

Got it, thanks!

jsfaint picture jsfaint on 6 Mar 2018

You can test https://github.com/neovim/python-client/pull/307 branch.

Shougo picture Shougo on 6 Mar 2018

neovim-python is upgrade to 0.2.4 which fix the windows issue.
But the gist patch doesn't work on windows.
After apply the patch on deoplete, there is no completion menu show up.

I enabled debug with

let $NVIM_PYTHON_LOG_FILE = 'd:\nvim_log'
let $NVIM_PYTHON_LOG_LEVEL = 'DEBUG'
let g:deoplete#enable_profile = 1
call deoplete#enable_logging('DEBUG', 'd:\deoplete.log')

But only got nvim_log_py3_script, there is no deoplete.log.
nvim_log_py3_script.zip

jsfaint picture jsfaint on 7 Mar 2018

But the gist patch doesn't work on windows.

Yes. It is intended behavior.
Current neovim-python does not support asyncio feature in Windows.

https://github.com/neovim/python-client/releases/tag/0.2.4

Shougo picture Shougo on 7 Mar 2018

@Shougo Thanks for the information. 馃憤

jsfaint picture jsfaint on 7 Mar 2018
Was this page helpful?
0 / 5 - 0 ratings

Related issues

callmekohei picture callmekohei  路  5Comments
lowski picture lowski  路  3Comments
westlywright picture westlywright  路  6Comments
tchia04 picture tchia04  路  3Comments
iscekic picture iscekic  路  6Comments