Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LanguageServer(?) runs forever on Revise.jl #630

Open
timholy opened this issue Apr 17, 2020 · 43 comments
Open

LanguageServer(?) runs forever on Revise.jl #630

timholy opened this issue Apr 17, 2020 · 43 comments
Assignees
Labels

Comments

@timholy
Copy link

timholy commented Apr 17, 2020

We've talked a fair bit about getting Revise to work properly in vscode's terminal, but I've finally noticed that some of my problems with vscode itself may be specific to Revise. All I have to do is dev Revise, navigate to .julia/dev/Revise, and do code . and I get a julia process that seemingly runs forever on my machine at 100% CPU, and all the nice F12 code navigation features of vscode don't work. But vscode is working for the majority of packages I hack on, so it seems something specific to Revise itself.

It should be noted that I start Revise from my startup.jl file. I haven't seriously tested whether that affects anything.

Not sure what info you need.

Revise 2.6.1
Julia 1.4.0

VSCode info:
Version: 1.44.1
Commit: a9f8623ec050e5f0b44cc8ce8204a1455884749f
Date: 2020-04-13T14:40:29.529Z
Electron: 7.1.11
Chrome: 78.0.3904.130
Node.js: 12.8.1
V8: 7.8.279.23-electron.0
OS: Linux x64 4.15.0-1079-oem

@davidanthoff
Copy link
Member

That should be fixed on master, it was a generic infinite loop that was not Revise specific :)

@timholy
Copy link
Author

timholy commented Apr 17, 2020

How do I check out master? Curiously I don't even have LanguageServer in my .julia/packages directory. This fact gave me some hesitancy in even filing the issue here.

@ZacLN
Copy link
Contributor

ZacLN commented Apr 17, 2020

The env used by vscode is stored in .vscode/extensions/**julia-vscode**/scripts/languageserver/packages. Pulling master for LanguageServer likely/definitely requires running a master version for StaticLint and probably SymbolServer

@davidanthoff
Copy link
Member

Actually, if you want to use pre-release versions I would suggest you just install the Julia Insider extension from the VS Code marketplace. I'm pushing new builds out to there very frequently, so I think there is very, very little delay relative to master typically, and then all the crash reporting etc. is much more useful for us than self-built versions :)

Insider right now for example has the fix alread.

Just make sure you don't install the regular and the insider build at the same time, that will cause trouble.

@timholy
Copy link
Author

timholy commented Jun 5, 2020

I'm running Julia Insider but something in vscode starts a Julia process that starts consuming more and more of my RAM; if I don't notice in time and kill it, I routinely have to hard-shutdown my machine by holding the power button.

Doesn't happen with Atom/Juno. Note that in top the process shows as julia rather than code.

It seems to happen most frequently when I edit Revise. It's possible it's related to julia-vscode/CSTParser.jl#180 since that came up in Revise/test/runtests.jl (https://github.com/timholy/Revise.jl/blob/ed7236de87acece0e4f731fae245fa5682c77c9c/test/runtests.jl#L941).

@pfitzseb
Copy link
Member

pfitzseb commented Jun 5, 2020

We also have a similar issue with Juno: JunoLab/Juno.jl#524

It's definitely something in CSTParser.jl (or our usage), since it only happens when static analysis is enabled.

@davidanthoff
Copy link
Member

Hm, this kind of suggests that we still have an infinite loop somewhere... The best thing would probably be if we could somehow get a reproducable example, because those kinds of bugs won't trigger our crash reporting.

@timholy is there a specific git commit of Revise.jl that would trigger this? Say some version of Revise.jl that we can check out, open it in VS Code and all hell breaks lose?

@davidanthoff
Copy link
Member

Also, I'm assigning the Showstopper label, in my mind fixing this is really crucial.

@ZacLN
Copy link
Contributor

ZacLN commented Jun 6, 2020

I'm going to strip out all the while-loops from CSTParser and StaticLint, that should hopefully catch this

@ZacLN
Copy link
Contributor

ZacLN commented Jun 6, 2020

@timholy , I assume (hope) this is still halting all functionality?

@timholy
Copy link
Author

timholy commented Jun 6, 2020

Agreed it's important, but it is sporadic. It does seem to happen when I use VSCode to hack on Revise, but I haven't quite pinned it down yet. I don't know if it's even related, but even julia-vscode/CSTParser.jl#180 has varied consequences: sometimes all parsing seems to stop beyond that line, other times it peters out more gradually. Here's a screenshot of my current session:

image

The offending line is near the middle of the window (line 1103). Notice that the yellow underlining of things it doesn't successfully resolve (see the miniature-text panner on the right) continue through the visible region and down as far as line 1337, and then it abruptly stops:

image

See the dearth of yellow-marked stuff thereafter.

Again, I have no idea if this is even related.

@ZacLN
Copy link
Contributor

ZacLN commented Jun 6, 2020

Unrelated I think (explanation on that issue).

It's definitely something in CSTParser.jl (or our usage), since it only happens when static analysis is enabled.

@pfitzseb - Juno only loads CSTParser (not StaticLint), right?

@davidanthoff
Copy link
Member

We could also add a counter to every while loop, and if it runs more than say 10k times, it throws an error? Or some other large number that makes sense. That would make this show up in crash reporting, which would make it most likely much easier to find the root cause?

@ZacLN
Copy link
Contributor

ZacLN commented Jun 6, 2020

Thats exactly what I've done (including a 10k limit, weirdly enough)

@aviatesk
Copy link
Member

aviatesk commented Jun 7, 2020

@pfitzseb - Juno only loads CSTParser (not StaticLint), right?

yeah, basically we call CSTParser.parse, and then add bindings by ourselves (mostly equivalent to StaticLint.mark_bindings) and then traverse EXPR, e.g.

@davidanthoff
Copy link
Member

Ok, we have a crash report on the insider channel for this, here is the stack trace:

CSTParser.CSTInfiniteLoop:
   at parse_string_or_cmd(::CSTParser.ParseState, ::Bool) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\components\strings.jl105)
   at parse_string_or_cmd(::CSTParser.ParseState) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\components\strings.jl25)
   at mLITERAL(::CSTParser.ParseState) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\spec.jl162)
   at parse_doc(::CSTParser.ParseState) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\CSTParser.jl182)
   at parse_block(::CSTParser.ParseState, ::Array{CSTParser.EXPR,1}, ::Tuple{Tokenize.Tokens.Kind}, ::Bool) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\components\internals.jl29)
   at parse_blockexpr(::CSTParser.ParseState, ::CSTParser.Head) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\components\keywords.jl298)
   at macro expansion (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\utils.jl58)
   at parse_kw(::CSTParser.ParseState) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\components\keywords.jl45)
   at parse_expression(::CSTParser.ParseState) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\CSTParser.jl46)
   at parse_doc(::CSTParser.ParseState) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\CSTParser.jl199)
   at parse(::CSTParser.ParseState, ::Bool) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\CSTParser.jl225)
   at parse(::String, ::Bool) (.\julialang.language-julia-insider-0.16.2\scripts\packages\CSTParser\src\CSTParser.jl171)
   at LanguageServer.Document(::String, ::String, ::Bool, ::LanguageServerInstance) (.\julialang.language-julia-insider-0.16.2\scripts\packages\LanguageServer\src\document.jl16)
   at load_folder(::String, ::LanguageServerInstance) (.\julialang.language-julia-insider-0.16.2\scripts\packages\LanguageServer\src\requests\init.jl109)
   at initialized_notification(::LanguageServer.InitializedParams, ::LanguageServerInstance, ::JSONRPC.JSONRPCEndpoint) (.\julialang.language-julia-insider-0.16.2\scripts\packages\LanguageServer\src\requests\init.jl170)
   at (::LanguageServer.var"#19#50"{LanguageServerInstance})(::JSONRPC.JSONRPCEndpoint, ::LanguageServer.InitializedParams) (.\julialang.language-julia-insider-0.16.2\scripts\packages\LanguageServer\src\languageserverinstance.jl281)
   at dispatch_msg(::JSONRPC.JSONRPCEndpoint, ::JSONRPC.MsgDispatcher, ::Dict{String,Any}) (.\julialang.language-julia-insider-0.16.2\scripts\packages\JSONRPC\src\typed.jl63)
   at run(::LanguageServerInstance) (.\julialang.language-julia-insider-0.16.2\scripts\packages\LanguageServer\src\languageserverinstance.jl305)
   at top-level scope (.\julialang.language-julia-insider-0.16.2\scripts\languageserver\main.jl59)
   at include(::Module, ::String) (Base.jl377)
   at exec_options(::Base.JLOptions) (client.jl288)
   at _start() (client.jl484)

@timholy
Copy link
Author

timholy commented Jun 9, 2020

Yesterday I had it jump into 100% CPU time twice but still wasn't able to detect any kind of pattern. A difference, though, is that memory usage stayed constant, and in neither case was LanguageServer indexing (if the lack of an "indexing..." indicator at the bottom of a window is an indication). I left the process running for almost 3 hours once.

In both cases I killed the process. Does that generate a crash report? Is there something better I can do?

@ZacLN
Copy link
Contributor

ZacLN commented Jun 9, 2020

Woop! I had a suspicion it was in that area as there's a call to seek in the mix. It may take me a short while to work out what the issue is as I don't think I wrote this code

@davidanthoff
Copy link
Member

@timholy are you on the insider channel for the extension? I pushed an update that now crashes the LS process if it ends up in an infinite loop. In theory it should be enough that you run that version, and then it should not stay at 100% for long, but instead it should crash and then send a crash report.

If that is not happening, but you're still running at a 100% for long, then that might indicate another problem... Killing the process won't send a crash report.

In general there are two Julia processes involved here: the language server (LS) process and the symbol server process. The status bar with the "indexing" tests corresponds to the symbol server process. Right now we think the problem is in the LS process, though (where the CSTParsing happens). Is there a way that you can see what the command line args were for the process that is at 100%? That should tell us exactly whether it is the LS or the symserv process.

@timholy
Copy link
Author

timholy commented Jun 9, 2020

@timholy are you on the insider channel for the extension?

I am indeed. Thanks for the debug commit!

Is there a way that you can see what the command line args were for the process that is at 100%?

top just says code.

@davidanthoff
Copy link
Member

@ZacLN do we know who wrote the code originally? Should we ping that person to try to help out? This is one of two showstoppers we have right now.

@non-Jedi
Copy link
Member

Git blame says that section of code was largely written/rewritten in julia-vscode/CSTParser.jl#24

@davidanthoff
Copy link
Member

@timholy we published v0.16.5 to the insider channel yesterday. It has more diagnostic code to figure out what is going on here. Could you try to open the offending project again? And ideally, hopefully, it will crash and send us a crash report with more information than we had before that will allow us to fix this.

@kdheepak
Copy link

@timholy you probably already know this, but you can run the following to find the exact command that vscode spun up as a child process.

$ ps -ex | grep julia
63591 ttys000  101:49.94 julia --project=/Users/USER/.cache/nvim/nvim_lsp/julials --startup-file=no --history-file=no -e         using Pkg;\012        Pkg.instantiate()\012        using LanguageServer; using SymbolServer;\012        depot_path = get(ENV, "JULIA_DEPOT_PATH", "")\012        project_path = dirname(something(Base.current_project(pwd()), Base.load_path_expand(LOAD_PATH[2])))\012        # Make sure that we only load packages from this environment specifically.\012        empty!(LOAD_PATH)\012        push!(LOAD_PATH, "@")\012        @info "Running language server" env=Base.load_path()[1] pwd() project_path depot_path\012        server = LanguageServer.LanguageServerInstance(stdin, stdout, project_path, depot_path);\012        server.runlinter = true;\012        run(server);\012
66420 ttys000    0:00.00 grep julia

I learnt this on #vim and it was useful in debugging what was going on.

@davidanthoff
Copy link
Member

We've got a new crash report here. It has the new diagnostics filled in.

@ZacLN
Copy link
Contributor

ZacLN commented Jun 13, 2020

I messed up the loop checks (fix here).

@timholy
Copy link
Author

timholy commented Jun 13, 2020

I've got all the new versions running, so we'll see if it catches anything. Thanks folks!

@aminya
Copy link
Contributor

aminya commented Jun 13, 2020

Not sure if related to this but I get these warnings until I stop julia.

using LanguageServer
Status `C:\Users\yahyaaba\Documents\GitHub\Julia\Project.toml`   
  [00ebfdb7] CSTParser v2.3.1
  [ffa9a821] DocumentFormat v2.2.0
  [2b0e0bc5] LanguageServer v3.0.0
  [b3cc710f] StaticLint v4.3.0
  [cf896787] SymbolServer v4.4.0
 Activating environment at `C:\Users\yahyaaba\Documents\GitHub\Julia\Project.toml`
   Updating registry at `C:\Users\yahyaaba\.julia\registries\General`
   Updating git-repo `https://github.com/JuliaRegistries/General.git`
   Updating `C:\Users\yahyaaba\Documents\GitHub\Julia\Project.toml`
  [2b0e0bc5] + LanguageServer v3.0.0
   Updating `C:\Users\yahyaaba\Documents\GitHub\Julia\Manifest.toml`
  [00ebfdb7] + CSTParser v2.3.1
  [ffa9a821] + DocumentFormat v2.2.0
  [48062228] + FilePathsBase v0.9.3
  [682c06a0] + JSON v0.21.0
  [2b0e0bc5] + LanguageServer v3.0.0
  [69de0a69] + Parsers v1.0.5
  [b3cc710f] + StaticLint v4.3.0
  [cf896787] + SymbolServer v4.4.0
  [0796e94c] + Tokenize v0.5.8
  [30578b45] + URIParser v0.4.1
  [2a0f44e3] + Base64 
  [ade2ca70] + Dates 
  [8ba89e20] + Distributed 
  [b77e0a4c] + InteractiveUtils 
  [76f85450] + LibGit2 
  [8f399da3] + Libdl 
  [56ddb016] + Logging 
  [d6f4376e] + Markdown 
  [a63ad114] + Mmap 
  [44cfe95a] + Pkg 
  [de0858da] + Printf 
  [3fa0cd96] + REPL 
  [9a3f8284] + Random 
  [ea8e919c] + SHA 
  [9e88b42a] + Serialization 
  [6462fe0b] + Sockets 
  [8dfed614] + Test 
  [cf7118a7] + UUIDs 
  [4ec0a83e] + Unicode 
[ Info: Precompiling LanguageServer [2b0e0bc5-e4fd-59b4-8912-456d1b03d8d7]
WARNING: Threads.Mutex is deprecated, use ReentrantLock instead.
  likely near C:\Users\yahyaaba\.julia\packages\SymbolServer\vTGsB\src\SymbolServer.jl:201
WARNING: Threads.RecursiveSpinLock is deprecated, use ReentrantLock instead.    
  likely near C:\Users\yahyaaba\.julia\packages\SymbolServer\vTGsB\src\SymbolServer.jl:201
WARNING: Threads.Mutex is deprecated, use ReentrantLock instead.
  likely near C:\Users\yahyaaba\.julia\packages\SymbolServer\vTGsB\src\SymbolServer.jl:201
WARNING: Threads.RecursiveSpinLock is deprecated, use ReentrantLock instead.    
  likely near C:\Users\yahyaaba\.julia\packages\SymbolServer\vTGsB\src\SymbolServer.jl:201

@aminya
Copy link
Contributor

aminya commented Jun 13, 2020

I checked the #master, and this does not happen. So I guess I should ask for registration of a new version instead 😄

@davidanthoff
Copy link
Member

@ZacLN so that means we might not have any crash report for this yet, right? Because the previous one was probably spurious?

@ZacLN
Copy link
Contributor

ZacLN commented Jun 13, 2020

No crash reports we've had so far represent the real bug

@davidanthoff
Copy link
Member

I'm removing the showstopper label because it seems we can't really manage to get a crash report for this easily, and so I think this shouldn't block our next release. It also isn't a regression in any case.

I'd say we leave all the diagnostic code we added in there and hope that it gets triggered once we ship the next version to everyone, not just the insider channel.

@timholy
Copy link
Author

timholy commented Jun 16, 2020

I've not seen this in some time, but this evening I triggered it again.

tim@diva:~/.julia/dev/Colors$ ps ax | grep julia
 3787 ?        Sl     0:39 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.5/scripts/environments/languageserver main.jl /home/tim/.julia/dev/Revise --debug=no /tmp/vsc-jl-cr-3707  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider
12261 ?        Sl     0:40 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.6/scripts/environments/languageserver main.jl /home/tim/.julia/dev/SnoopCompile --debug=no /tmp/vsc-jl-cr-12186  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider
13178 ?        Sl     0:43 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.6/scripts/environments/languageserver main.jl /home/tim/.julia/environments/v1.4 --debug=no /tmp/vsc-jl-cr-13064  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider
17460 ?        Sl     1:30 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.6/scripts/environments/languageserver main.jl /home/tim/.julia/environments/v1.6 --debug=no /tmp/vsc-jl-cr-17382  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider
24032 ?        Sl     0:41 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.6/scripts/environments/languageserver main.jl /home/tim/.julia/environments/v1.4 --debug=no /tmp/vsc-jl-cr-23909  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider
27511 pts/12   S+     0:00 grep --color=auto julia

I have 5 separate code windows open, to Revise, FixedPointNumbers, ColorTypes, ColorVectorSpace, and SnoopCompile. Interestingly, I noticed the CPU load when editing ColorVectorSpace's README (!). Also perhaps not coincidentally, spell-checking has never worked for me.

I am heading to bed but if there are diagnostics I can run, I will leave all my windows open through the morning.

@davidanthoff
Copy link
Member

This is definitely in the LS... I take it that it didn't crash, though, right?

@ZacLN we didn't add these loop traps to LanguageServer.jl and StaticLint.jl, or did we? Maybe we need to have them everywhere to get to the bottom of this?

@timholy I don't know what we could do further with this particular run... The most likely explanation is that Julia is stuck in some endless while loop in the LS, but I don't know how we might be able to figure out which one without adding additional debug code... But you might have an idea :)

@timholy
Copy link
Author

timholy commented Jun 16, 2020

Yes, this time (and for the last several times) it's not growing in its memory consumption. Also, closing the code window terminates the CPU-intensive process (something that hasn't always happened in the past).

@ZacLN
Copy link
Contributor

ZacLN commented Jun 16, 2020

@davidanthoff, no we left it at CSTParser and StaticLint. I'll widen our net

@timholy
Copy link
Author

timholy commented Jun 20, 2020

Happened again today (the growing-memory variant). Got this from ps ax | grep code:

15673 ?        Rl     3:56 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.8/scripts/environments/languageserver main.jl /home/tim/.julia/dev/Revise --debug=no /tmp/vsc-jl-cr-15590  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider

I was editing test/runtests.jl and test/common.jl, though I had the whole package open.

The pattern seems to be: if it's the growing-memory version, I have to kill the process manually (just shutting down vscode doesn't stop it). If it's not growing in memory consumption, then quitting vscode terminates the job.

@davidanthoff
Copy link
Member

I always thought VS Code was actually killing the LS process when you shut it down, but this suggests it is not, and instead is relying on the LS shutting down in response to a shutdown request. Which of course won't be processed anymore once we are in that infinite loop... I think the only hope we have here is to add more of these while loop checks that @ZacLN started.

@ZacLN
Copy link
Contributor

ZacLN commented Jun 20, 2020

Coincidentally, we've had a few hits on Azure for the existing loop checks in CSTParser

@timholy
Copy link
Author

timholy commented Jun 21, 2020

I'm getting slightly more convinced that the offending file might be Revise/test/common.jl. Is there something I can do to test this theory?

In case it helps, got this today:

 4654 ?        Rl    16:59 /home/tim/src/julia-1/usr/bin/julia --startup-file=no --history-file=no --depwarn=no --project=/home/tim/.vscode/extensions/julialang.language-julia-insider-0.16.8/scripts/environments/languageserver main.jl /home/tim/.julia/dev/Revise --debug=no /tmp/vsc-jl-cr-4560  /home/tim/.config/Code/User/globalStorage/julialang.language-julia-insider

and it was not of the memory-growing variety, but it didn't quit when I closed vscode. So much for the patterns I thought I'd observed above 🤷.

@davidanthoff
Copy link
Member

@ZacLN we're getting a number of hits in crash reporting on the latest version, e.g. here. Does that help?

@timholy
Copy link
Author

timholy commented Jun 30, 2020

I can't access those reports but one caution: I noticed a number of crashes occurring while I was in the middle of a make clean && make on master while also running vscode. If those happen to be me (I have enabled telemetry), probably worth ignoring.

@davidanthoff
Copy link
Member

I think we should never crash, regardless of what you are doing :) I think the reports came from someone else, though.

@davidanthoff davidanthoff modified the milestones: Next Patch, Backlog Aug 17, 2020
@davidanthoff davidanthoff removed this from the Backlog milestone Oct 15, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

8 participants