This repository was archived by the owner on Apr 14, 2022. It is now read-only.
Repository navigation
This repository was archived by the owner on Apr 14, 2022. It is now read-only.
Language server hangs on analysis stage #1834
Description
Environment data
- Language Server version: Microsoft Python Language Server version 0.4.127.0
- OS and version: Linuxmint 19.2 (Ubuntu 18)
- Python version (& distribution if applicable, e.g. Anaconda): python3.5
Expected behaviour
Works
Actual behaviour
Doesn't work
Logs
[Info - 10:44:22 AM] Analysis cache path: /home/pz/.cache/Microsoft/Python Language Server
[Info - 10:44:22 AM] Microsoft Python Language Server version 0.4.127.0
[Info - 10:44:22 AM] Workspace root: /home/pz/defence360/src/rpm-tests
[Info - 10:44:22 AM] GetCurrentSearchPaths /opt/alt/python35/bin/python3
[Info - 10:44:22 AM] Interpreter search paths:
[Info - 10:44:22 AM] /opt/alt/python35/lib/python3.5
[Info - 10:44:22 AM] /opt/alt/python35/lib/python3.5/plat-linux
[Info - 10:44:22 AM] /opt/alt/python35/lib/python3.5/lib-dynload
[Info - 10:44:22 AM] /home/pz/defence360/src/asyncclient
[Info - 10:44:22 AM] /home/pz/.local/lib/python3.5/site-packages
[Info - 10:44:22 AM] /opt/alt/python35/local/lib/python3.5/dist-packages
[Info - 10:44:22 AM] /opt/alt/python35/lib/python3/dist-packages
[Info - 10:44:22 AM] /opt/alt/python35/lib/python3.5/dist-packages
[Info - 10:44:22 AM] User search paths:
[Info - 10:44:23 AM] Initializing for /opt/alt/python35/bin/python3
Watching /opt/alt/python35/lib/python3.5
Watching /home/pz/defence360/src/asyncclient
Watching /home/pz/.local/lib/python3.5/site-packages
Watching /opt/alt/python35/lib/python3/dist-packages
Watching /opt/alt/python35/local/lib/python3.5/dist-packages
[Info - 10:44:24 AM] Analysis caching mode: None.
Opening document file:///home/pz/defence360/src/rpm-tests/fixtures/hosting_panel/plesk.py
Analysis of fixtures.hosting_panel.plesk (User) queued. Dependencies: os, subprocess, distutils.version, pathlib, xml.etree, xml.etree.ElementTree, fixtures.hosting_panel, fixtures.hosting_panel.abstract, utils
Import: os /opt/alt/python35/lib/python3.5/os.py
Import: subprocess /opt/alt/python35/lib/python3.5/subprocess.py
Import: distutils.version /opt/alt/python35/lib/python3.5/distutils/version.py
Import: pathlib /opt/alt/python35/lib/python3.5/pathlib.py
Import: xml.etree /opt/alt/python35/lib/python3.5/xml/etree/__init__.py
Import: xml.etree.ElementTree /opt/alt/python35/lib/python3.5/xml/etree/ElementTree.py
Import: fixtures.hosting_panel /home/pz/defence360/src/rpm-tests/fixtures/hosting_panel/__init__.py
[skipped a lot of lines]
Analysis of modules loop on depth 0 in 293.89 ms:
utils(User)
utils.webshield(User)
Create compiled (scraped): _datetime /opt/alt/python35/lib/python3.5/lib-dynload/_datetime.cpython-35m-x86_64-linux-gnu.so /opt/alt/python35/lib/python3.5/lib-dynload
Import: optparse /opt/alt/python35/lib/python3.5/optparse.py
Import: ast /opt/alt/python35/lib/python3.5/ast.py
Analysis of modules loop [inspect(Library), ast(Library)] failed. System.ArgumentNullException: Value cannot be null. (Parameter 'ast')
at Microsoft.Python.Analysis.Analyzer.Evaluation.ExpressionEval..ctor(IServiceContainer services, IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Evaluation\ExpressionEval.cs:line 43
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 119
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 118
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.EnsureModule(IPythonModule& module) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 104
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.EnsureModule(PythonVariableModule& variableModule) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 94
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.Microsoft.Python.Analysis.Analyzer.Handlers.IImportedVariableHandler.EnsureModule(PythonVariableModule& module)
at Microsoft.Python.Analysis.Analyzer.Handlers.ImportHandler.HandleImport(ModuleName moduleImportExpression, NameExpression asNameExpression, Boolean forceAbsolute) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\ImportHandler.cs:line 63
at Microsoft.Python.Analysis.Analyzer.Handlers.ImportHandler.HandleImport(ImportStatement node) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\ImportHandler.cs:line 46
at Microsoft.Python.Analysis.Analyzer.AnalysisWalker.Walk(ImportStatement node) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\AnalysisWalker.cs:line 85
at Microsoft.Python.Parsing.Ast.ImportStatement.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\ImportStatement.cs:line 48
at Microsoft.Python.Parsing.Ast.SuiteStatement.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\SuiteStatement.cs:line 40
at Microsoft.Python.Parsing.Ast.PythonAst.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\PythonAst.cs:line 86
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 123
at Microsoft.Python.Analysis.Analyzer.PythonAnalyzerSession.AnalyzeLoop(IDependencyChainLoopNode`1 loopNode, Stopwatch stopWatch) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\PythonAnalyzerSession.cs:line 409
at Microsoft.Python.Analysis.Analyzer.PythonAnalyzerSession.Analyze(IDependencyChainNode node, AsyncCountdownEvent ace, Stopwatch stopWatch) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\PythonAnalyzerSession.cs:line 284
Import: faker.generator /opt/alt/python35/local/lib/python3.5/dist-packages/faker/generator.py
Import: faker.factory /opt/alt/python35/local/lib/python3.5/dist-packages/faker/factory.py
Import: faker /opt/alt/python35/local/lib/python3.5/dist-packages/faker/__init__.py
Import: faker.config /opt/alt/python35/local/lib/python3.5/dist-packages/faker/config.py
Analysis of modules loop on depth 1 in 18.27 ms:
faker.factory(Library)
faker(Library)
Analysis version 285 has been completed in 3910.72 ms with 135 entries analyzed and 59 entries skipped.
Analysis version 1361 of 52 entries has started.
[skipped a lot of lines]
Analysis of sys(Stub) canceled (no AST yet).
Analysis version 1386 has been completed in 0.44 ms with 19 entries analyzed and 32 entries skipped.
Analysis of cryptography.x509.general_name (Library) on depth 4 completed in 5.76 ms.
Import: cryptography.hazmat.backends.openssl.decode_asn1 /opt/alt/python35/lib/python3/dist-packages/cryptography/hazmat/backends/openssl/decode_asn1.py
Import: cryptography.hazmat.primitives.serialization /opt/alt/python35/lib/python3/dist-packages/cryptography/hazmat/primitives/serialization.py
Analysis of cryptography.hazmat.backends.openssl.x509 (Library) on depth 3 completed in 8.42 ms.
Analysis of urllib3.packages (Library) on depth 3 completed in 0.25 ms.
Analysis of modules loop [urllib.request(Library), http.cookiejar(Library)] failed. System.ArgumentNullException: Value cannot be null. (Parameter 'ast')
at Microsoft.Python.Analysis.Analyzer.Evaluation.ExpressionEval..ctor(IServiceContainer services, IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Evaluation\ExpressionEval.cs:line 43
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 119
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 118
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.EnsureModule(IPythonModule& module) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 104
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.EnsureModule(PythonVariableModule& variableModule) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 94
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.Microsoft.Python.Analysis.Analyzer.Handlers.IImportedVariableHandler.EnsureModule(PythonVariableModule& module)
at Microsoft.Python.Analysis.Analyzer.Handlers.ImportHandler.HandleImport(ModuleName moduleImportExpression, NameExpression asNameExpression, Boolean forceAbsolute) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\ImportHandler.cs:line 63
at Microsoft.Python.Analysis.Analyzer.Handlers.ImportHandler.HandleImport(ImportStatement node) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\ImportHandler.cs:line 46
at Microsoft.Python.Analysis.Analyzer.AnalysisWalker.Walk(ImportStatement node) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\AnalysisWalker.cs:line 85
at Microsoft.Python.Parsing.Ast.ImportStatement.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\ImportStatement.cs:line 48
at Microsoft.Python.Parsing.Ast.SuiteStatement.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\SuiteStatement.cs:line 40
at Microsoft.Python.Parsing.Ast.PythonAst.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\PythonAst.cs:line 86
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 123
at Microsoft.Python.Analysis.Analyzer.PythonAnalyzerSession.AnalyzeLoop(IDependencyChainLoopNode`1 loopNode, Stopwatch stopWatch) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\PythonAnalyzerSession.cs:line 409
at Microsoft.Python.Analysis.Analyzer.PythonAnalyzerSession.Analyze(IDependencyChainNode node, AsyncCountdownEvent ace, Stopwatch stopWatch) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\PythonAnalyzerSession.cs:line 284
Import: asn1crypto.keys /opt/alt/python35/lib/python3/dist-packages/asn1crypto/keys.py
Import: cryptography.hazmat.primitives.asymmetric.ec /opt/alt/python35/lib/python3/dist-packages/cryptography/hazmat/primitives/asymmetric/ec.py
Import: cryptography.hazmat.primitives.asymmetric.rsa /opt/alt/python35/lib/python3/dist-packages/cryptography/hazmat/primitives/asymmetric/rsa.py
Import: cryptography.x509.general_name /opt/alt/python35/lib/python3/dist-packages/cryptography/x509/general_name.py
Analysis of six.moves.cPickle (Stub) queued. Dependencies: pickle (stub)
Analysis version 1387 of 51 entries has started.
[skipped a lot of lines]
Analysis of modules loop [requests(Library), requests.utils(Library), requests.models(Library), requests.api(Library), requests.sessions(Library), requests.auth(Library), requests.adapters(Library)] failed. System.ArgumentNullException: Value cannot be null. (Parameter 'ast')
at Microsoft.Python.Analysis.Analyzer.Evaluation.ExpressionEval..ctor(IServiceContainer services, IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Evaluation\ExpressionEval.cs:line 43
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 119
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 118
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.EnsureModule(IPythonModule& module) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 104
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.EnsureModule(PythonVariableModule& variableModule) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 94
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.Microsoft.Python.Analysis.Analyzer.Handlers.IImportedVariableHandler.EnsureModule(PythonVariableModule& module)
at Microsoft.Python.Analysis.Analyzer.Handlers.ImportHandler.AssignVariables(FromImportStatement node, IImportSearchResult imports, PythonVariableModule variableModule) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\FromImportHandler.cs:line 76
at Microsoft.Python.Analysis.Analyzer.Handlers.ImportHandler.HandleFromImport(FromImportStatement node) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\FromImportHandler.cs:line 45
at Microsoft.Python.Analysis.Analyzer.AnalysisWalker.Walk(FromImportStatement node) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\AnalysisWalker.cs:line 81
at Microsoft.Python.Parsing.Ast.FromImportStatement.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\FromImportStatement.cs:line 58
at Microsoft.Python.Parsing.Ast.SuiteStatement.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\SuiteStatement.cs:line 40
at Microsoft.Python.Parsing.Ast.PythonAst.Walk(PythonWalker walker) in E:\A\_work\2\s\src\Parsing\Impl\Ast\PythonAst.cs:line 86
at Microsoft.Python.Analysis.Analyzer.Handlers.LoopImportedVariableHandler.WalkModule(IPythonModule module, PythonAst ast) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\Handlers\LoopImportedVariableHandler.cs:line 123
at Microsoft.Python.Analysis.Analyzer.PythonAnalyzerSession.AnalyzeLoop(IDependencyChainLoopNode`1 loopNode, Stopwatch stopWatch) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\PythonAnalyzerSession.cs:line 409
at Microsoft.Python.Analysis.Analyzer.PythonAnalyzerSession.Analyze(IDependencyChainNode node, AsyncCountdownEvent ace, Stopwatch stopWatch) in E:\A\_work\2\s\src\Analysis\Ast\Impl\Analyzer\PythonAnalyzerSession.cs:line 284
Full log
[Info - 10:44:22 AM] Analysis cache path: /home/pz/.cache/Microsoft/Python Lang - Pastebin.com
Code Snippet / Additional lnformation
Metadata
Metadata
Assignees
Labels
No labels
Activity
MikhailArkhipov commentedon Dec 11, 2019
This should be fixed by #1757 in 0.5. Could you try daily
zztalker commentedon Dec 11, 2019
This doesn't help. I've not seen in log exceptions but [Analyzing in the background, 3 items left ] not changed for infinity time.
New log here https://drive.google.com/file/d/1Wi_J4iPq1A3hpoY3KeK8ry0ymoGR7-bl/view?usp=sharing
zztalker commentedon Dec 13, 2019
Mikhail Arkhipov (@MikhailArkhipov) I think that it depends on my imported libs because it hangs not always (always on my working repo, wich huge). How could I get a debug the Language Server to understood on which file it catches the infinity loop?
MikhailArkhipov commentedon Dec 13, 2019
It certainly does depend on libraries. However, it does not necessarily means hang. Sometimes it is a stuck message or analysis completes except couple of modules. Is CPU still getting consumed? Does any editor functionality (hover, completions) are available?
zztalker commentedon Dec 13, 2019
Yep, it is continuously consuming CPU. What could I do from my side to help improve PLS?
hover works well, the outline is shown for files except one from which I've started (if start editing file it also fills outline section), completions work well (on current version 0.5.7, on early versions I experienced a problem with it).
MikhailArkhipov commentedon Dec 13, 2019
Analysis would consume quite a bit more than 1.3%, it runs multiple tasks on multiple cores. Generally LS is not inactive when there is at least some activity in VS Code. Typing re-runs analysis incrementally on changed files and its dependents. Hover also cost a bit of CPU although not much. Or does it spike to 10-20% or higher?
zztalker commentedon Dec 13, 2019
Hmm, as I see CPU consumption came from vs-code process.
jakebailey commentedon Dec 13, 2019
If it's VS Code itself, then it's probably out of our control. You should be able to go into "Help > Open Process Explorer" to see what part of VS Code is using the CPU.
zztalker commentedon Dec 14, 2019
I've done some exploration and discovered that if I open just part of my workspace (separate folder - for example) everything works.
The process explorer does not show anything interesting. (On screenshot I've just started VSCode in problem workspace with opened problem file, [Analyzing in background, 2 items left...] - infinitely showing.
jakebailey commentedon Dec 14, 2019
Based on that screenshot, htop is saying that it's the GPU process that's eating CPU. I really don't think that can be related to something that the LS is doing; we can't do anything about VS Code's CPU usage. The only thing we can look into is the hanging you've reported.
The only thing I can see in your logs is a reload during the analysis, so I would also consider setting
"python.analysis.watchSearchPaths": falseand seeing if that changes anything.MikhailArkhipov commentedon Dec 14, 2019
Sounds like electron issue to me. I'd suggest reporting to vscode repo, there are some CPU/GPU issues there.
MikhailArkhipov commentedon Dec 16, 2019
File watch turned off by default in #1841.
LS 0.5.10+