Skip to content
This repository has been archived by the owner on Jul 31, 2023. It is now read-only.

Language server keep restarting indexing service? #32

Closed
Yevgnen opened this issue Jun 25, 2019 · 10 comments
Closed

Language server keep restarting indexing service? #32

Yevgnen opened this issue Jun 25, 2019 · 10 comments

Comments

@Yevgnen
Copy link

Yevgnen commented Jun 25, 2019

Completion is almost not working when I'm using Microsoft's python language server. By 'almost', the *Message* prints LSP :: The task was cancelled. most of the time and about 5% percentage of time I may get completions. I test it in vscode in the same virtualenv and the same language server binary, the analyzer run so fast (average < 5s on my MacBook Pro 2019) like this

Untitled

The same message can be found in the follow logs, but I notice the indexing service is keep restarting.

The content of the *lsp-log* buffer is

Command "/Users/user/.emacs.d/mspyls/Microsoft.Python.LanguageServer" is present on the path.
Command "pyls" is present on the path.
Found the following clients for /Users/user/git/competitions/ppdai/tags.py: (server-id mspyls, priority 1), (server-id pyls, priority -1)
The following clients were selected based on priority: (server-id mspyls, priority 1)
Analysis cache path: /Users/user/Library/Caches/Microsoft/Python Language Server
GetCurrentSearchPaths /Users/user/.pyenv/versions/env/bin/python 
Python search paths:
    /private/var/folders/_3/5xmnbvq133s33v6135dvlmfr0000gn/T/svht41pp.khm
    /Users/user/.pyenv/versions/3.7.3/lib/python3.7
    /Users/user/.pyenv/versions/3.7.3/lib/python3.7/lib-dynload
    /Users/user/.pyenv/versions/env/lib/python3.7/site-packages
Configuration search paths:
    /Users/user/.pyenv/versions/3.7.3/lib/python37.zip
    /Users/user/.pyenv/versions/3.7.3/lib/python3.7
    /Users/user/.pyenv/versions/3.7.3/lib/python3.7/lib-dynload
    /Users/user/.pyenv/versions/env/lib/python3.7/site-packages
Microsoft Python Language Server version 0.2.96.0
Initializing for /Users/user/.pyenv/versions/env/bin/python
Reloading modules... 
Reloading modules... 
done.
Analysis restarted.
done.
Analysis restarted.
Reloading modules... 
done.
Analysis restarted.
Reloading modules... 
Reloading modules... 
done.
Analysis restarted.
done.
Analysis restarted.
Reloading modules... 
Reloading modules... 
Reloading modules... 
Reloading modules... 
done.
Analysis restarted.
Reloading modules... 
done.
Analysis restarted.
done.
Analysis restarted.
done.
Analysis restarted.
done.
Analysis restarted.

and the content of *lsp-log: mspyls:38548* is here. Variable company-lsp-cache-candidates is set to 'auto.

I have no idea if the issue comes from lsp-mode or lsp-mode-ms or company-lap or the language server.

@yyoncho Do you have any idea about this? Thank you very much.

@yyoncho
Copy link
Member

yyoncho commented Jun 25, 2019

@Yevgnen usually the way to go is to compare the lsp-mode -> LS communication with vscode -> LS communication. Although the protocol is standard the servers are tested and adjusted to work with vscode which is PITA for us(lsp-mode team). So it will will be very helpful for us if you can take a look and share your observations.

@Yevgnen
Copy link
Author

Yevgnen commented Jun 26, 2019

@yyoncho Thanks for your advice. I've not figured out how to see the communication of vscode...

But after a quick look of the language server logs of vscode

Starting Microsoft Python language server.
Downloading https://pvsc.azureedge.net/python-language-server-stable/Python-Language-Server-osx-x64.0.3.20.nupkg... complete
Unpacking archive... done
[Info  - 8:20:37 AM] Analysis cache path: /Users/user/Library/Caches/Microsoft/Python Language Server
[Info  - 8:20:38 AM] GetCurrentSearchPaths /Users/user/.pyenv/versions/env/bin/python 
[Info  - 8:20:38 AM] Interpreter search paths:
[Info  - 8:20:38 AM]     /private/var/folders/_3/5xmnbvq133s33v6135dvlmfr0000gn/T/zhbrmwzz.mtc
[Info  - 8:20:38 AM]     /Users/user/.pyenv/versions/3.7.3/lib/python3.7
[Info  - 8:20:38 AM]     /Users/user/.pyenv/versions/3.7.3/lib/python3.7/lib-dynload
[Info  - 8:20:38 AM]     /Users/user/.pyenv/versions/env/lib/python3.7/site-packages
[Info  - 8:20:38 AM] User search paths:
[Info  - 8:20:40 AM] Microsoft Python Language Server version 0.3.20.0
[Info  - 8:20:40 AM] Initializing for /Users/user/.pyenv/versions/env/bin/python
Opening document file:///Users/user/Git/competitions/ppdai/tags.py
Analysis of competitions.ppdai.tags(User) queued
Import:  sklearn.feature_extraction.text /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/feature_extraction/text.py 
Import:  sklearn.feature_selection /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/feature_selection/__init__.py 
Import:  sklearn.model_selection /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/model_selection/__init__.py 
Import:  sklearn.metrics /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/metrics/__init__.py 
Import:  sklearn.tree /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/tree/__init__.py 
Analysis of sklearn.tree(Library) queued
Analysis of sklearn.feature_selection(Library) queued
Analysis of sklearn.model_selection(Library) queued
Analysis of sklearn.metrics(Library) queued
Import:  sklearn.tree.tree /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/tree/tree.py 
Import:  sklearn.tree.export /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/tree/export.py 
Import:  sklearn.feature_selection.univariate_selection /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/feature_selection/univariate_selection.py 
Import:  sklearn.feature_selection.variance_threshold /Users/user/.pyenv/versions/env/lib/python3.7/site-packages/sklearn/feature_selection/variance_threshold.py 
....

The User search paths and Configuration search paths are a bit different. I will try to test it more.

@Yevgnen
Copy link
Author

Yevgnen commented Jun 26, 2019

@yyoncho Now I comment out this line(I have no idea about the meaning of the param and can not find it here), and it just seems works!

The logs looks fine (no restarted logs and the configure looks empty):

Command "/Users/user/.emacs.d/mspyls/Microsoft.Python.LanguageServer" is present on the path.
Command "pyls" is present on the path.
Found the following clients for /Users/user/git/competitions/ppdai/tags.py: (server-id mspyls, priority 1), (server-id pyls, priority -1)
The following clients were selected based on priority: (server-id mspyls, priority 1)
Analysis cache path: /Users/user/Library/Caches/Microsoft/Python Language Server
GetCurrentSearchPaths /Users/user/.pyenv/versions/env/bin/python 
Python search paths:
    /private/var/folders/_3/5xmnbvq133s33v6135dvlmfr0000gn/T/1mbu01fk.dix
    /Users/user/.pyenv/versions/3.7.3/lib/python3.7
    /Users/user/.pyenv/versions/3.7.3/lib/python3.7/lib-dynload
    /Users/user/.pyenv/versions/env/lib/python3.7/site-packages
Configuration search paths:

and the analysis can be finished once

"Analyzing in background, 28 items left..."
"Analyzing in background, 520 items left..."
"Analyzing in background, 4924 items left..."
"Analyzing in background, 6515 items left..."
"Analyzing in background, 6227 items left..."
"Analyzing in background, 6164 items left..."
"Analyzing in background, 6064 items left..."
"Analyzing in background, 6036 items left..."
"Analyzing in background, 5946 items left..."
"Analyzing in background, 5822 items left..."
"Analyzing in background, 5599 items left..."
"Analyzing in background, 5394 items left..."
"Analyzing in background, 5246 items left..."
"Analyzing in background, 5073 items left..."
"Analyzing in background, 4943 items left..."
"Analyzing in background, 4747 items left..."
"Analyzing in background, 4584 items left..."
"Analyzing in background, 4437 items left..."
"Analyzing in background, 4284 items left..."
"Analyzing in background, 4157 items left..."
"Analyzing in background, 4053 items left..."
"Analyzing in background, 3981 items left..."
"Analyzing in background, 3903 items left..."
"Analyzing in background, 3808 items left..."
"Analyzing in background, 3660 items left..."
"Analyzing in background, 3816 items left..."
"Analyzing in background, 3811 items left..."
"Analyzing in background, 3694 items left..."
"Analyzing in background, 3598 items left..."
"Analyzing in background, 3482 items left..."
"Analyzing in background, 3371 items left..."
"Analyzing in background, 3273 items left..."
"Analyzing in background, 3185 items left..."
"Analyzing in background, 3125 items left..."
"Analyzing in background, 3061 items left..."
"Analyzing in background, 3015 items left..."
"Analyzing in background, 2909 items left..."
"Analyzing in background, 2817 items left..."
"Analyzing in background, 2716 items left..."
"Analyzing in background, 2663 items left..."
"Analyzing in background, 2523 items left..."
"Analyzing in background, 2435 items left..."
"Analyzing in background, 2272 items left..."
"Analyzing in background, 2046 items left..."
"Analyzing in background, 1874 items left..."
"Analyzing in background, 1762 items left..."
"Analyzing in background, 1729 items left..."
"Analyzing in background, 1673 items left..."
"Analyzing in background, 1533 items left..."
"Analyzing in background, 1383 items left..."
"Analyzing in background, 1331 items left..."
"Analyzing in background, 1254 items left..."
"Analyzing in background, 1242 items left..."
"Analyzing in background, 1169 items left..."
"Analyzing in background, 1061 items left..."
"Analyzing in background, 992 items left..."
"Analyzing in background, 942 items left..."
"Analyzing in background, 809 items left..."
"Analyzing in background, 663 items left..."
"Analyzing in background, 627 items left..."
"Analyzing in background, 408 items left..."
"Analyzing in background, 192 items left..."
"Analyzing in background, 80 items left..."

@yyoncho
Copy link
Member

yyoncho commented Jun 26, 2019

@yyoncho Now I comment out this line(I have no idea about the meaning of the param and can not find it here), and it just seems works!

The param is not part of the spec but it is something specific for the microsoft language server. It is really hard for me to tell why this param fixes your issue. I tried using mspyls on my machine and it worked fine.

Here it is the vscode configuration which we have to mimic: https://github.com/microsoft/vscode-python/tree/master/src/client/activation/languageServer

There are a few initialization options that are missing, e. g.

:analysisUpdates t
:asyncStartup t

I don't know whether some of these will fix your issue. AFAIK we have to do more work on this adapter to make it on par with vscode one.

@Yevgnen
Copy link
Author

Yevgnen commented Jun 26, 2019 via email

@yyoncho
Copy link
Member

yyoncho commented Jun 26, 2019

@Yevgnen no, I didn't. I am not a python programmer and I am not very familiar with how they work and what is the expected behaviour when you are using such.

@smallzhan
Copy link
Contributor

After comment the line that @Yevgnen mentioned, my problem solved. The problem happens with some big python file, with no virtualenv, both in macos and windows.

The problem is:

Open a new file at first time, the completion, as well as jump to /back works smoothly. After some editing, something like "Reloading modules..." appears in lsp-log buffer, the source file is re-analyzed, then, some built-in modules such as sys, time are labels as "unresolved import", thus no completion , nor some other lsp related functions.

There is no "Reloading modules..." issues in my lsp-log buffer, and everything works normally when the relevant line is commented.

@yyoncho
Copy link
Member

yyoncho commented Jun 27, 2019

I think that I found out why this is happening: if you take a look here the microsoft pyls server code here:
https://github.com/microsoft/python-language-server/blob/75fb0447e01924804ea729468271538e2e2b3324/src/LanguageServer/Impl/LanguageServer.cs#L376

... the server is restarting the analysis if some of the initial search paths have changed. IMO the issue is that the search path in emacs side is wrong and points to a file that changes very often and the result is that the analysis is cancelled too often. IMO if we delete searchPath argument we will lose some functionality so the correct fix is to unify the path calculation in lsp-mode and vscode. Here it is the corresponding piece of code in vscode: https://github.com/microsoft/vscode-python/blob/master/src/client/activation/languageServer/analysisOptions.ts#L129

@smallzhan
Copy link
Contributor

@yyoncho I check the file https://github.com/microsoft/vscode-python/blob/master/src/client/activation/languageServer/analysisOptions.ts#L129 and start a debug session in vscode, there is some interesting observations,

  1. searchPaths in initializationOptions is an array, and is initalized as a empty array []. While in emacs, it seems to be a json map. https://github.com/emacs-lsp/lsp-python-ms/blob/master/lsp-python-ms.el#L145
  2. DatabasePath option in properties points to the language server path, and there is a comment says that the setting is not used since ms-pyls 0.2.92+. In emacs, it points to a customized path setting by lsp-python-ms-cache-dir.

@yyoncho
Copy link
Member

yyoncho commented Jun 28, 2019

@smallzhan thank you, are you interested in providing a PR to unify with what vscode does?

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants