neovim slow closing time #671

sitilge · 2018-02-26T10:38:31Z

Problems summary

I'm using neovim 0.2.2-3 on the latest stock arch kernel 4.15.4 I noticed it yesterday that it takes some 3-4 seconds before nvim closes.

Expected

Fast neovim closing.

Environment Information

deoplete version(SHA1): b14aa70
OS: arch linux 4.15.5 stock kernel
neovim/Vim version: 0.2.2-3
: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: Release

## Remote Plugins
  - OK: Up to date

## terminal
  - INFO: key_backspace (kbs) terminfo entry: key_backspace=\177
  - INFO: key_dc (kdch1) terminfo entry: key_dc=\E[3~
  - INFO: $XTERM_VERSION=''
  - INFO: $TERM_PROGRAM=''
  - INFO: $SSH_TTY=''

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

## 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:
    /usr/bin/python2 does not have the "neovim" module. :help |provider-python|
    /usr/bin/python2.7 does not have the "neovim" module. :help |provider-python|
    python2.6 not found in search path or not executable.
    /usr/bin/python is Python 3.6 and cannot provide Python 2.
  - ERROR: Python provider error
    - ADVICE:
      - provider/pythonx: Could not load Python 2:
          /usr/bin/python2 does not have the "neovim" module. :help |provider-python|
          /usr/bin/python2.7 does not have the "neovim" module. :help |provider-python|
          python2.6 not found in search path or not executable.
          /usr/bin/python is Python 3.6 and cannot provide Python 2.
  - INFO: Executable: Not found

## Python 3 provider (optional)
  - INFO: `g:python3_host_prog` is not set.  Searching for python3 in the environment.
  - INFO: Executable: /usr/bin/python3
  - INFO: Python3 version: 3.6.4
  - INFO: python3-neovim version: 0.2.1
  - OK: Latest python3-neovim is installed: 0.2.1

## Ruby provider (optional)
  - INFO: Ruby: ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux]
  - WARNING: Missing "neovim" gem.
    - ADVICE:
      - Run in shell: gem install neovim
      - Is the gem bin directory in $PATH? Check `gem environment`.
      - If you are using rvm/rbenv/chruby, try "rehashing".

## Node provider (optional)
  - INFO: Node: v9.6.1
  - 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!)

" Enable deoplete on startup
let g:deoplete#enable_at_startup=0
autocmd InsertEnter * call deoplete#enable()

" Deoplete tab-complete
inoremap <expr><tab> pumvisible() ? "\<c-n>" : "\<tab>"

function! OnTermClose()
	if len(filter(range(1, bufnr('$')), 'buflisted(v:val)')) == 1
		:quit!
	else
		call feedkeys(" ")
	endif
endfunction

au TermClose * nested call OnTermClose()

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

start neovim
start deoplete (actually start typing something, since the calls are async)
stop neovim

The text was updated successfully, but these errors were encountered:

Shougo · 2018-02-27T02:11:51Z

I have tested it, but I cannot reproduce the problem.

My version is: NVIM v0.2.3-770-gf588113

Please test neovim latest version.

I'm using neovim 0.2.2-3 on the latest stock arch kernel 4.15.4 I noticed it yesterday that it takes some 3-4 seconds before nvim closes.

It just Arch Linux latest. It is not neovim latest.

Shougo · 2018-02-27T02:32:32Z

Workaround: You can disable parallel feature by g:deoplete#num_processes.

Shougo · 2018-02-27T02:34:21Z

start neovim

Please check you have executed nvim -u minimalinit.vim.

If other people can reproduce the problem, I will check it though.

sitilge · 2018-02-27T09:00:30Z

I did not say it was the latest neovim.

The latest neovim release (which is the one you are using) was released just 7 hours before your comment 🤣

Shougo · 2018-02-27T09:03:46Z

I build neovim everyday :-)

stinovlas · 2018-02-28T08:27:05Z

I have the same problem. Also, I noticed that deoplete process sometimes keeps running even after the neovim is terminated (and puts a high load on the CPU). It seems that it was introduced somewhere between commits 51cfc34 (where I don't have the problem) and b14aa70 (where I do).

Shougo · 2018-02-28T08:53:48Z

Really?

Ping @blueyed

I can revert the change easily.

Shougo · 2018-02-28T08:54:43Z

If the change is affected, I think your neovim has error messages.

Shougo · 2018-02-28T08:55:46Z

@stinovlas @sitilge Please use git bisect.

Pending the problem until bisecting.

stinovlas · 2018-03-05T15:44:53Z

The problem does not appear all the time, so it took me some time to bisect it. I narrowed my search to commit a4d4db9. I don't know whether changes in this commit might introduce the issue, but I haven't experienced it before this commit.

blueyed · 2018-03-05T16:10:01Z

@stinovlas
Thanks for investigating, but that commit/change should only have an effect if there are any errors in the first place.
Have you checked that VimLeavePre is not being skipped for you, e.g. because of using vim-qf, which does not use nested with its autocommand that might use q to close the last window?
What sources are you using? Also deoplete-jedi?

milisims · 2018-03-05T19:38:58Z

I'm currently working and am not able to investigate this issue, but I just wanted to report I am having the same issue. If I manually call deoplete#enable() in my init.vim, then there is no slowdown. If I call it with any of autocmd InsertEnter,CursorHold,TextChanged, there will be a slow down. I will follow and report later.

Shougo · 2018-03-06T02:03:45Z

@matthsims @stinovlas

Please use git bisect and test the minimal vimrc.

Shougo · 2018-03-06T02:05:14Z

Still pending.
I cannot investing the problem.

Please provide more detailed information.

Shougo · 2018-03-06T05:35:22Z

And please test the patch.

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

stinovlas · 2018-03-06T14:24:41Z

@blueyed
I'm sorry that I'm unable to provide more helpful answers. I use Neovim for my work, but I'm no expert. I don't use vim-qf (but I use ale, which also creates quickfix windows) and I do use deoplete-jedi.

When I will have a little spare time, I will apply the patch and try to work with minimal vimrc for a while.

milisims · 2018-03-06T16:54:15Z

Okay, I think I figured it out. I think I have a successful reproducible min config below.
Some of my config was executed twice before startup, which caused two autocmd to be registered. deoplete#enable() is called twice successfully, so two autocmds in the config make it happen.

Minimal init.vim:

packadd deoplete.nvim
set updatetime=100
autocmd CursorHold * call deoplete#enable()
autocmd CursorHold * call deoplete#enable()

The updatetime set is not necessary, but makes testing faster.
init.vim is in ~/.config/nvim with deoplete cloned in ~/.config/pack/autocomplete/opt

I was unable to apply the patch.

$ git apply asyncio.diff                                                         
fatal: patch fragment without header at line 284: @@ -82,7 +85,8 @@ class Deoplete(logger.LoggingMixin):

I'm not very familiar with git, sorry!

I will use git bisect shortly

blueyed · 2018-03-06T17:01:51Z

Please also check $NVIM_LOG_FILE (defaults to ~/.local/share/nvim/log - there should be entries if a process gets killed).

milisims · 2018-03-06T17:19:32Z

There's nothing there for me.

milisims · 2018-03-06T17:44:04Z

Bisect landed me at 38b9a65, although it might be off a little because deoplete wasn't functioning correctly during those last commits.

Shougo · 2018-03-07T01:34:57Z

@matthsims

I was unable to apply the patch.

Please use patch -p1 instead.

#645 (comment)

Shougo · 2018-03-07T01:40:36Z

@matthsims
OK. I have reproduced the problem with master and not reproduced the problem with the patch.

No problem.

Shougo · 2018-03-12T10:05:20Z

I have created the branch for it.

blueyed · 2018-03-12T18:04:59Z

This is how it looks for me when it happens:
deoplete log:

2018-03-12 18:53:06,916 DEBUG    [26088] (deoplete.core) on_event: VimLeavePre
2018-03-12 18:53:06,918 DEBUG    (deoplete.jedi.server) Input closed.  Shutting down.
2018-03-12 18:53:06,918 DEBUG    (deoplete.jedi.server) Input closed.  Shutting down.
2018-03-12 18:53:06,934 DEBUG    [26101] (deoplete.child) _read: 9855 bytes
2018-03-12 18:53:06,934 DEBUG    [26101] (deoplete.child) main_loop: on_event begin
2018-03-12 18:53:06,934 DEBUG    [26101] (deoplete.child) on_event: Source: buffer
2018-03-12 18:53:06,935 DEBUG    [26101] (deoplete.child) on_event: Source: member
2018-03-12 18:53:06,935 DEBUG    [26101] (deoplete.child) main_loop: end

nvim log

2018/03/12 18:53:06 INFO  26080 channel_create_event:231: new channel 23 (job): function gitgutter#process_buffer[8]..gitgutter#diff#run_diff[67]..gitgutter#async#execute:11
2018/03/12 18:53:10 WARN  26080 call_set_error:594: RPC: ch 6 was closed by the client
2018/03/12 18:53:10 WARN  26080 call_set_error:594: RPC: ch 7 was closed by the client
2018/03/12 18:53:10 WARN  26080 call_set_error:594: RPC: ch 9 was closed by the client
2018/03/12 18:53:10 WARN  26080 call_set_error:594: RPC: ch 8 was closed by the client
2018/03/12 18:53:10 INFO  26080 process_stop:218: Sending SIGTERM to pid 26088
2018/03/12 18:53:10 INFO  26080 process_stop:234: Starting job kill timer
2018/03/12 18:53:10 INFO  26080 process_stop:218: Sending SIGTERM to pid 26160
2018/03/12 18:53:10 INFO  26080 process_stop:218: Sending SIGTERM to pid 28629

So it takes 4 seconds from the VimLeavePre to Neovim closing the channels / sending the SIGTERM (to 26088).

Anyway, the asyncio branch hopefully allows us to skip debugging this further.

Shougo · 2018-03-13T02:55:44Z

OK.

stinovlas · 2018-03-16T11:32:04Z

I checked out the asyncio branch 3 days ago and I was unable to reproduce the problem ever since. It seems to be fixed.

sitilge · 2018-03-16T20:31:59Z

The asyncio branch works like a charm. Thank you so much!

Fix #645 #671 asyncio loop support

Shougo added cannot reproduce help wanted labels Feb 27, 2018

Shougo added the pending label Feb 28, 2018

Shougo added bug performance and removed cannot reproduce help wanted pending labels Mar 7, 2018

Shougo mentioned this issue Mar 7, 2018

neovim-python asyncio support #676

Closed

Shougo added a commit that referenced this issue Mar 12, 2018

Fix #645 #671 asyncio loop support

47b86cf

sitilge closed this as completed Mar 16, 2018

Shougo added a commit that referenced this issue Mar 18, 2018

Fix #645 #671 asyncio loop support

bef2124

Shougo added a commit that referenced this issue Mar 18, 2018

Merge pull request #678 from Shougo/asyncio

026687a

Fix #645 #671 asyncio loop support

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

neovim slow closing time #671

neovim slow closing time #671

sitilge commented Feb 26, 2018

Shougo commented Feb 27, 2018 •

edited

Loading

Shougo commented Feb 27, 2018

Shougo commented Feb 27, 2018

sitilge commented Feb 27, 2018

Shougo commented Feb 27, 2018

stinovlas commented Feb 28, 2018

Shougo commented Feb 28, 2018

Shougo commented Feb 28, 2018

Shougo commented Feb 28, 2018 •

edited

Loading

stinovlas commented Mar 5, 2018

blueyed commented Mar 5, 2018

milisims commented Mar 5, 2018

Shougo commented Mar 6, 2018 •

edited

Loading

Shougo commented Mar 6, 2018 •

edited

Loading

Shougo commented Mar 6, 2018

stinovlas commented Mar 6, 2018

milisims commented Mar 6, 2018 •

edited

Loading

blueyed commented Mar 6, 2018

milisims commented Mar 6, 2018

milisims commented Mar 6, 2018

Shougo commented Mar 7, 2018 •

edited

Loading

Shougo commented Mar 7, 2018

Shougo commented Mar 12, 2018

blueyed commented Mar 12, 2018

Shougo commented Mar 13, 2018

stinovlas commented Mar 16, 2018

sitilge commented Mar 16, 2018

neovim slow closing time #671

neovim slow closing time #671

Comments

sitilge commented Feb 26, 2018

Problems summary

Expected

Environment Information

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

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

Shougo commented Feb 27, 2018 • edited Loading

Shougo commented Feb 27, 2018

Shougo commented Feb 27, 2018

sitilge commented Feb 27, 2018

Shougo commented Feb 27, 2018

stinovlas commented Feb 28, 2018

Shougo commented Feb 28, 2018

Shougo commented Feb 28, 2018

Shougo commented Feb 28, 2018 • edited Loading

stinovlas commented Mar 5, 2018

blueyed commented Mar 5, 2018

milisims commented Mar 5, 2018

Shougo commented Mar 6, 2018 • edited Loading

Shougo commented Mar 6, 2018 • edited Loading

Shougo commented Mar 6, 2018

stinovlas commented Mar 6, 2018

milisims commented Mar 6, 2018 • edited Loading

blueyed commented Mar 6, 2018

milisims commented Mar 6, 2018

milisims commented Mar 6, 2018

Shougo commented Mar 7, 2018 • edited Loading

Shougo commented Mar 7, 2018

Shougo commented Mar 12, 2018

blueyed commented Mar 12, 2018

Shougo commented Mar 13, 2018

stinovlas commented Mar 16, 2018

sitilge commented Mar 16, 2018

Shougo commented Feb 27, 2018 •

edited

Loading

Shougo commented Feb 28, 2018 •

edited

Loading

Shougo commented Mar 6, 2018 •

edited

Loading

Shougo commented Mar 6, 2018 •

edited

Loading

milisims commented Mar 6, 2018 •

edited

Loading

Shougo commented Mar 7, 2018 •

edited

Loading