Nimlangsever + nimsuggest processes non being killed when using choosenim

[arkanoid87]

TLDR; each vscode instance runs a nimlangserver process, each nim tab file runs two nimsuggest processes, when vscode is closed nimlangserver is not killed and one nimsuggest goes defunct. Repeatable steps until OOM

OS

$ cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.3 LTS"

VSCode via official repo .deb

$ type code
code is /usr/bin/code
$ code --version
1.86.0
05047486b6df5eb8d44b2ecd70ea3bdf775fd937
x64

nimlangserver installed/upgraded via nimble

$ type nimlangserver 
nimlangserver is /home/arkanoid/.nimble/bin/nimlangserver
$ nimlangserver --version
1.2.0

nimsuggest installed/upgraded via nimble

$ type nimsuggest 
nimsuggest is /home/arkanoid/.nimble/bin/nimsuggest
$ nimsuggest --version
Nim Compiler Version 2.0.2 [Linux: amd64]
Compiled at 2023-12-15
Copyright (c) 2006-2023 by Andreas Rumpf

git hash: c4c44d10df8a14204a75c34e499def200589cb7c
active boot switches: -d:release -d:danger --gc:markAndSweep

minimal project (karax frontend, prologue backend, atlas scaffold): https://github.com/arkanoid87/nim_vscode_playground

Test scenario setup:

$ git clone https://github.com/arkanoid87/nim_vscode_playground
$ cd nim_vscode_playground
$ atlas install vscode_playground.nimble
$ nim frontend
$ nim backend
(optional nim run_backend)

Monitor processes (optional) run in different windows:

`watch -c "ps -ae | grep nimlangserver" `
`watch -c "ps -ae | grep nimsuggest"`

1. killall nimlangserver && killall nimsuggest && killall code && code .: nimlangserver =+ 1
2. open new tab for src/front/front.nim: nimsuggest += 2
3. open new tab for src/back/back.nim: nimsuggest += 2
4. close vscode (ensure code process not running)
5. final: nimlangserver = 1, nimsuggest = 4 (one is )
6. reopen vscode code . nimlangserver =+ 1
7. open new tab for src/front/front.nim: nimsuggest += 2
8. open new tab for src/back/back.nim: nimsuggest += 2
9. final: nimlangserver = 2, nimsuggest = 8 (2 are )

[supremestranger]

Same thing happens on Windows 11

[nickysn]

What are the command line options of nimsuggest, i.e. what does
ps ax | grep nimsuggest
print exactly, while VS code is running?

[arkanoid87]

What are the command line options of nimsuggest, i.e. what does ps ax | grep nimsuggest print exactly, while VS code is running?

By doing so, I realized that using watch -c "ps -ae | grep *" was not giving a good picture.
Moving from watch -c "ps -ae | grep *" to pstree -a <nimlangserver pid>

After opening VSCode: no nimlangserver/nimsuggest processes
After opening src/front/front.nim:

nimlangserver --stdio
  ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │   └─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │       └─2*[{nimsuggest}]
  └─2*[{nimlangserver}]

After opening src/back/back.nim:

nimlangserver --stdio
  ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │   └─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │       └─2*[{nimsuggest}]
  ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/back/back.nim --v4 --autobind --clientProcessId:530580
  │   └─nimsuggest /home/arkanoid/nim/vscode_playground/src/back/back.nim --v4 --autobind --clientProcessId:530580
  │       └─2*[{nimsuggest}]
  └─3*[{nimlangserver}]

after closing vscode (one of the two nimsuggest goes defunct)

nimlangserver --stdio
  ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │   └─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │       └─2*[{nimsuggest}]
  ├─(nimsuggest)
  └─2*[{nimlangserver}]

after reopoening vscode on src/front/front.nim I have 2 nimlangserver processes:
n1 (old one)

nimlangserver --stdio
  ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │   └─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:530580
  │       └─2*[{nimsuggest}]
  ├─(nimsuggest)
  └─2*[{nimlangserver}]

n2 (new one)

nimlangserver --stdio
  ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:566371
  │   └─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:566371
  │       └─2*[{nimsuggest}]
  └─2*[{nimlangserver}]

I see two points here:

• nim.project setting in .vscode/settings.json seems honored as I see one nimsuggest process for each independent Nim source import tree
• for some reason, only one of the two nimsuggest processes is killed and goes defunct possibly because parent is monitoring children processes

[nickysn]

Can you make the following changes in nimlangserver.nim.cfg:

• uncomment the line --define:"chronicles_log_level=TRACE"
• comment the line --define:"chronicles_log_level=DEBUG"
• uncomment the line --define:"chronicles_sinks=textlines[file]"
  Finally, it should look like that:

--threads:on
--define:"async_backend=asyncdispatch"
--define:"chronicles_default_output_device=stderr"
--define:"chronicles_colors=None"
--define:"chronicles_disable_thread_id"
--define:"debugLogging"
--define:"chronicles_log_level=TRACE"
#--define:"chronicles_log_level=DEBUG"
--define:"chronicles_timestamps=None"
--define:"chronicles_sinks=textlines[file]"

Then recompile nimlangserver using nimble build. This will produce a nimlangserver binary that produces a debug log in a file, called nimlangserver.log. Can you attach the log that is produced, after doing the following:

1. open VS code
2. open a Nim file, wait until nimsuggest is initalized
3. close VS code
   Another thing you can check is whether Visual Studio Code is leaving other processes. Also, when sampling the processes left, wait at least a second or two, before checking, as some of these processes may require some extra time, until they terminate.

[arkanoid87]

↓ VSCode open

TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":0,\"method\":\"initialize\",\"params\":{\"processId\":1042484,\"clientInfo\":{\"name\":\"Visual Studio Code\",\"version\":\"1.86.0\"},\"locale\":\"en\",\"rootPath\":\"/home/arkanoid/nim/vscode_playground\",\"rootUri\":\"file:///home/arkanoid/nim/vscode_playground\",\"capabilities\":{\"workspace\":{\"applyEdit\":true,\"workspaceEdit\":{\"documentChanges\":true,\"resourceOperations\":[\"create\",\"rename\",\"delete\"],\"failureHandling\":\"textOnlyTransactional\",\"normalizesLineEndings\":true,\"changeAnnotationSupport\":{\"groupsOnLabel\":true}},\"configuration\":true,\"didChangeWatchedFiles\":{\"dynamicRegistration\":true,\"relativePatternSupport\":true},\"symbol\":{\"dynamicRegistration\":true,\"symbolKind\":{\"valueSet\":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26]},\"tagSupport\":{\"valueSet\":[1]},\"resolveSupport\":{\"properties\":[\"location.range\"]}},\"codeLens\":{\"refreshSupport\":true},\"executeCommand\":{\"dynamicRegistration\":true},\"didChangeConfiguration\":{\"dynamicRegistration\":true},\"workspaceFolders\":true,\"foldingRange\":{\"refreshSupport\":true},\"semanticTokens\":{\"refreshSupport\":true},\"fileOperations\":{\"dynamicRegistration\":true,\"didCreate\":true,\"didRename\":true,\"didDelete\":true,\"willCreate\":true,\"willRename\":true,\"willDelete\":true},\"inlineValue\":{\"refreshSupport\":true},\"inlayHint\":{\"refreshSupport\":true},\"diagnostics\":{\"refreshSupport\":true}},\"textDocument\":{\"publishDiagnostics\":{\"relatedInformation\":true,\"versionSupport\":false,\"tagSupport\":{\"valueSet\":[1,2]},\"codeDescriptionSupport\":true,\"dataSupport\":true},\"synchronization\":{\"dynamicRegistration\":true,\"willSave\":true,\"willSaveWaitUntil\":true,\"didSave\":true},\"completion\":{\"dynamicRegistration\":true,\"contextSupport\":true,\"completionItem\":{\"snippetSupport\":true,\"commitCharactersSupport\":true,\"documentationFormat\":[\"markdown\",\"plaintext\"],\"deprecatedSupport\":true,\"preselectSupport\":true,\"tagSupport\":{\"valueSet\":[1]},\"insertReplaceSupport\":true,\"resolveSupport\":{\"properties\":[\"documentation\",\"detail\",\"additionalTextEdits\"]},\"insertTextModeSupport\":{\"valueSet\":[1,2]},\"labelDetailsSupport\":true},\"insertTextMode\":2,\"completionItemKind\":{\"valueSet\":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25]},\"completionList\":{\"itemDefaults\":[\"commitCharacters\",\"editRange\",\"insertTextFormat\",\"insertTextMode\",\"data\"]}},\"hover\":{\"dynamicRegistration\":true,\"contentFormat\":[\"markdown\",\"plaintext\"]},\"signatureHelp\":{\"dynamicRegistration\":true,\"signatureInformation\":{\"documentationFormat\":[\"markdown\",\"plaintext\"],\"parameterInformation\":{\"labelOffsetSupport\":true},\"activeParameterSupport\":true},\"contextSupport\":true},\"definition\":{\"dynamicRegistration\":true,\"linkSupport\":true},\"references\":{\"dynamicRegistration\":true},\"documentHighlight\":{\"dynamicRegistration\":true},\"documentSymbol\":{\"dynamicRegistration\":true,\"symbolKind\":{\"valueSet\":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26]},\"hierarchicalDocumentSymbolSupport\":true,\"tagSupport\":{\"valueSet\":[1]},\"labelSupport\":true},\"codeAction\":{\"dynamicRegistration\":true,\"isPreferredSupport\":true,\"disabledSupport\":true,\"dataSupport\":true,\"resolveSupport\":{\"properties\":[\"edit\"]},\"codeActionLiteralSupport\":{\"codeActionKind\":{\"valueSet\":[\"\",\"quickfix\",\"refactor\",\"refactor.extract\",\"refactor.inline\",\"refactor.rewrite\",\"source\",\"source.organizeImports\"]}},\"honorsChangeAnnotations\":true},\"codeLens\":{\"dynamicRegistration\":true},\"formatting\":{\"dynamicRegistration\":true},\"rangeFormatting\":{\"dynamicRegistration\":true,\"rangesSupport\":true},\"onTypeFormatting\":{\"dynamicRegistration\":true},\"rename\":{\"dynamicRegistration\":true,\"prepareSupport\":true,\"prepareSupportDefaultBehavior\":1,\"honorsChangeAnnotations\":true},\"documentLink\":{\"dynamicRegistration\":true,\"tooltipSupport\":true},\"typeDefinition\":{\"dynamicRegistration\":true,\"linkSupport\":true},\"implementation\":{\"dynamicRegistration\":true,\"linkSupport\":true},\"colorProvider\":{\"dynamicRegistration\":true},\"foldingRange\":{\"dynamicRegistration\":true,\"rangeLimit\":5000,\"lineFoldingOnly\":true,\"foldingRangeKind\":{\"valueSet\":[\"comment\",\"imports\",\"region\"]},\"foldingRange\":{\"collapsedText\":false}},\"declaration\":{\"dynamicRegistration\":true,\"linkSupport\":true},\"selectionRange\":{\"dynamicRegistration\":true},\"callHierarchy\":{\"dynamicRegistration\":true},\"semanticTokens\":{\"dynamicRegistration\":true,\"tokenTypes\":[\"namespace\",\"type\",\"class\",\"enum\",\"interface\",\"struct\",\"typeParameter\",\"parameter\",\"variable\",\"property\",\"enumMember\",\"event\",\"function\",\"method\",\"macro\",\"keyword\",\"modifier\",\"comment\",\"string\",\"number\",\"regexp\",\"operator\",\"decorator\"],\"tokenModifiers\":[\"declaration\",\"definition\",\"readonly\",\"static\",\"deprecated\",\"abstract\",\"async\",\"modification\",\"documentation\",\"defaultLibrary\"],\"formats\":[\"relative\"],\"requests\":{\"range\":true,\"full\":{\"delta\":true}},\"multilineTokenSupport\":false,\"overlappingTokenSupport\":false,\"serverCancelSupport\":true,\"augmentsSyntaxTokens\":true},\"linkedEditingRange\":{\"dynamicRegistration\":true},\"typeHierarchy\":{\"dynamicRegistration\":true},\"inlineValue\":{\"dynamicRegistration\":true},\"inlayHint\":{\"dynamicRegistration\":true,\"resolveSupport\":{\"properties\":[\"tooltip\",\"textEdits\",\"label.tooltip\",\"label.location\",\"label.command\"]}},\"diagnostic\":{\"dynamicRegistration\":true,\"relatedDocumentSupport\":false}},\"window\":{\"showMessage\":{\"messageActionItem\":{\"additionalPropertiesSupport\":true}},\"showDocument\":{\"support\":true},\"workDoneProgress\":true},\"general\":{\"staleRequestSupport\":{\"cancel\":true,\"retryOnContentModified\":[\"textDocument/semanticTokens/full\",\"textDocument/semanticTokens/range\",\"textDocument/semanticTokens/full/delta\"]},\"regularExpressions\":{\"engine\":\"ECMAScript\",\"version\":\"ES2020\"},\"markdown\":{\"parser\":\"marked\",\"version\":\"1.1.0\"},\"positionEncodings\":[\"utf-16\"]},\"notebookDocument\":{\"synchronization\":{\"dynamicRegistration\":true,\"executionSummarySupport\":true}}},\"trace\":\"off\",\"workspaceFolders\":[{\"uri\":\"file:///home/arkanoid/nim/vscode_playground\",\"name\":\"vscode_playground\"}]}}"
DBG Router: dispatching                        method=initialize id=0
DBG Initialize received...                    
DBG Registering monitor for process            pid=1042484
DBG Router: sending response                   method=initialize id=0
TRC Router: response                           response="{\"capabilities\":{\"textDocumentSync\":{\"openClose\":true,\"change\":1,\"willSave\":false,\"willSaveWaitUntil\":false,\"save\":{\"includeText\":true}},\"completionProvider\":{\"resolveProvider\":false,\"triggerCharacters\":[\".\"]},\"hoverProvider\":true,\"signatureHelpProvider\":{\"triggerCharacters\":[\"(\",\",\"]},\"declarationProvider\":true,\"definitionProvider\":true,\"typeDefinitionProvider\":true,\"implementationProvider\":null,\"referencesProvider\":true,\"documentHighlightProvider\":true,\"documentSymbolProvider\":true,\"workspaceSymbolProvider\":true,\"codeActionProvider\":true,\"codeLensProvider\":null,\"documentLinkProvider\":null,\"colorProvider\":null,\"documentFormattingProvider\":null,\"documentRangeFormattingProvider\":null,\"documentOnTypeFormattingProvider\":null,\"renameProvider\":{\"prepareProvider\":true},\"executeCommandProvider\":{\"commands\":[\"nimlangserver.restart\",\"nimlangserver.recompile\",\"nimlangserver.checkProject\"]},\"inlayHintProvider\":{\"resolveProvider\":false},\"workspace\":{\"workspaceFolders\":{\"supported\":null,\"changeNotifications\":null}},\"experimental\":null}}"
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"method\":\"initialized\",\"params\":{}}"
DBG Router: dispatching                        method=initialized id=null
DBG Client initialized.                       
DBG Requesting configuration from the client  
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"method\":\"textDocument/didOpen\",\"params\":{\"textDocument\":{\"uri\":\"file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"languageId\":\"nim\",\"version\":1,\"text\":\"import karax/[karax, karaxdsl, vdom]\\n\\nproc main() =\\n  proc createDom(data: Routerdata): VNode =\\n    buildHtml(tdiv):\\n      text \\\"Hello, world!\\\"\\n\\n  setRenderer createDom, \\\"ROOT\\\"\\n\\nif isMainModule:\\n  main()\\n\"}}}"
DBG Router: dispatching                        method=textDocument/didOpen id=null
DBG New document opened for URI:               uri=file:///home/arkanoid/nim/vscode_playground/src/front/front.nim
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":1,\"result\":null}"
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":1,\"method\":\"textDocument/documentSymbol\",\"params\":{\"textDocument\":{\"uri\":\"file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\"}}}"
DBG Router: dispatching                        method=textDocument/documentSymbol id=1
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":2,\"method\":\"textDocument/inlayHint\",\"params\":{\"textDocument\":{\"uri\":\"file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\"},\"range\":{\"start\":{\"line\":0,\"character\":0},\"end\":{\"line\":11,\"character\":0}}}}"
DBG Router: dispatching                        method=textDocument/inlayHint id=2
DBG inlayHint received...                     
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":2,\"result\":[{\"project\":[\"src/back/back.nim\",\"src/front/front.nim\"],\"projectMapping\":[],\"test-project\":\"\",\"buildOnSave\":false,\"buildCommand\":\"c\",\"runOutputDirectory\":\"\",\"lintOnSave\":true,\"enableNimsuggest\":false,\"provider\":\"lsp\",\"useNimsuggestCheck\":false,\"logNimsuggest\":false,\"licenseString\":\"\",\"nimsuggestRestartTimeout\":60,\"nimprettyIndent\":2,\"nimprettyMaxLineLen\":80,\"lsp\":{\"path\":\"\"},\"inlayHints\":{\"typeHints\":{\"enable\":true},\"exceptionHints\":{\"enable\":true,\"hintStringLeft\":\"🔔\",\"hintStringRight\":\"\"}},\"debug\":{\"type\":\"lldb\"},\"notificationVerbosity\":\"info\"}]}"
DBG Got response for the didChangeConfiguration registration: res=null
DBG Received the following configuration       configuration="[{\"project\":[\"src/back/back.nim\",\"src/front/front.nim\"],\"projectMapping\":[],\"test-project\":\"\",\"buildOnSave\":false,\"buildCommand\":\"c\",\"runOutputDirectory\":\"\",\"lintOnSave\":true,\"enableNimsuggest\":false,\"provider\":\"lsp\",\"useNimsuggestCheck\":false,\"logNimsuggest\":false,\"licenseString\":\"\",\"nimsuggestRestartTimeout\":60,\"nimprettyIndent\":2,\"nimprettyMaxLineLen\":80,\"lsp\":{\"path\":\"\"},\"inlayHints\":{\"typeHints\":{\"enable\":true},\"exceptionHints\":{\"enable\":true,\"hintStringLeft\":\"🔔\",\"hintStringRight\":\"\"}},\"debug\":{\"type\":\"lldb\"},\"notificationVerbosity\":\"info\"}]"
DBG getProjectFile                             project=/home/arkanoid/nim/vscode_playground/src/front/front.nim
INF Starting nimsuggest                        root=/home/arkanoid/nim/vscode_playground/src/front/front.nim timeout=120000 path=nimsuggest fullPath=/home/arkanoid/.nimble/bin/nimsuggest workingDir=/home/arkanoid/nim/vscode_playground
TRC Sending notification                       notification=$/progress params="{\"token\":\"Creating nimsuggest for /home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"value\":{\"kind\":\"begin\",\"title\":\"Creating nimsuggest for /home/arkanoid/nim/vscode_playground/src/front/front.nim\"}}"
DBG Document associated with the following projectFile uri=file:///home/arkanoid/nim/vscode_playground/src/front/front.nim projectFile=/home/arkanoid/nim/vscode_playground/src/front/front.nim
DBG Started nimsuggest                         port=33481 root=/home/arkanoid/nim/vscode_playground/src/front/front.nim
DBG ShowMessage                                message="Nimsuggest initialized for /home/arkanoid/nim/vscode_playground/src/front/front.nim"
TRC Sending notification                       notification=window/showMessage params="{\"type\":3,\"message\":\"Nimsuggest initialized for /home/arkanoid/nim/vscode_playground/src/front/front.nim\"}"
DBG Running diagnostics                        uri=file:///home/arkanoid/nim/vscode_playground/src/front/front.nim
TRC Sending notification                       notification=$/progress params="{\"token\":\"Checking file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"value\":{\"kind\":\"begin\",\"title\":\"Checking project /home/arkanoid/nim/vscode_playground/src/front/front.nim\"}}"
DBG processQueue                               size=1
DBG Started...                                 benchmark="chk \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0" command="chk \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG timeoutCallback is set                     timeout=120000 command="chk \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
TRC Sending notification                       notification=$/progress params="{\"token\":\"Creating nimsuggest for /home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"value\":{\"kind\":\"end\",\"title\":\"\"}}"
DBG Sending result(s)                          length=75 command="chk \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG CPU Time                                   benchmark="chk \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0" time=0.251 command="chk \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG Started...                                 benchmark="inlayHints \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":1:0:12:0 +exceptionHints" command="inlayHints \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":1:0:12:0 +exceptionHints"
DBG timeoutCallback is set                     timeout=120000 command="inlayHints \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":1:0:12:0 +exceptionHints"
TRC Sending notification                       notification=$/progress params="{\"token\":\"Checking file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"value\":{\"kind\":\"end\",\"title\":\"\"}}"
DBG Found diagnostics                          file={}
DBG Sending result(s)                          length=0 command="inlayHints \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":1:0:12:0 +exceptionHints"
DBG CPU Time                                   benchmark="inlayHints \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":1:0:12:0 +exceptionHints" time=0.249 command="inlayHints \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":1:0:12:0 +exceptionHints"
DBG Started...                                 benchmark="known \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0" command="known \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG timeoutCallback is set                     timeout=120000 command="known \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG Router: sending response                   method=textDocument/inlayHint id=2
TRC Router: response                           response=[]
DBG Sending result(s)                          length=1 command="known \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG CPU Time                                   benchmark="known \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0" time=0.250 command="known \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG Started...                                 benchmark="outline \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0" command="outline \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG timeoutCallback is set                     timeout=120000 command="outline \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG Sending result(s)                          length=2 command="outline \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG CPU Time                                   benchmark="outline \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0" time=0.250 command="outline \"/home/arkanoid/nim/vscode_playground/src/front/front.nim\":0:0"
DBG Router: sending response                   method=textDocument/documentSymbol id=1
TRC Router: response                           response="[{\"name\":\"main\",\"kind\":12,\"deprecated\":null,\"location\":{\"uri\":\"file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"range\":{\"start\":{\"line\":2,\"character\":5},\"end\":{\"line\":2,\"character\":9}}},\"containerName\":null},{\"name\":\"createDom\",\"kind\":12,\"deprecated\":null,\"location\":{\"uri\":\"file:///home/arkanoid/nim/vscode_playground/src/front/front.nim\",\"range\":{\"start\":{\"line\":3,\"character\":7},\"end\":{\"line\":3,\"character\":16}}},\"containerName\":null}]"
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":3,\"result\":null}"
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":4,\"result\":null}"
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":3,\"method\":\"shutdown\"}"
DBG Router: dispatching                        method=shutdown id=3
DBG Shutting down                             
DBG stopping child nimsuggest processes       
DBG Stopping nimsuggest for                    root=/home/arkanoid/nim/vscode_playground/src/front/front.nim

↑ VSCode closed

nimlangserver process still running here
code process(es) not running here

pstree -a at this moment (sorry created this on second run so PIDs may not be the same as in log above)

systemd splash
  ├─systemd --user
  │   ├─nimlangserver --stdio
  │   │   ├─(nimsuggest)
  │   │   └─{nimlangserver}
  │   ├─nimsuggest /home/arkanoid/nim/vscode_playground/src/front/front.nim --v4 --autobind --clientProcessId:1062269
  │   │   └─2*[{nimsuggest}]

↓ killall nimlangserger

DBG Terminated via signal                      sig=15
DBG child nimsuggest processes already stopped: CHECK!

EOF

[nickysn]

Hmm, here's what the end of the log is supposed to look after closing VS Code:

TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"id\":3,\"method\":\"shutdown\"}"
DBG Router: dispatching                        method=shutdown id=3
DBG Shutting down                             
DBG stopping child nimsuggest processes       
DBG Stopping nimsuggest for                    root=/home/nickysn/work/langserver/nimlangserver.nim
TRC Shutdown complete                         
DBG Router: sending response                   method=shutdown id=3
TRC Router: response                           response=null
TRC Received message                           message="{\"jsonrpc\":\"2.0\",\"method\":\"exit\"}"
DBG Router: dispatching                        method=exit id=null
DBG Quitting process                          
DBG exiting main thread                        isShutdown=true

After that, I get no leftover processes - neither nimlangserver, nor nimsuggest. So, this means something in your setup is different, and we need to figure this out, so I can reproduce the bug. Can you provide more information about your VS Code plugins and versions, your desktop environment (I'm using GNOME), window manager, etc.

[arkanoid87]

Interesting. Seems actually related to my environment.
I post my env again

OS

$ cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.3 LTS"

VSCode

$ type code
code is /usr/bin/code
$ code --version
1.86.0
05047486b6df5eb8d44b2ecd70ea3bdf775fd937
x64

Gnome 42.9

I'll try to repeat the experiment in a pristine VSCode environment (with just nim extension) and give feedback

[arkanoid87]

I've created a new VSCode profile (File > Preferences > Profiles) with nothing except nim-lang extension. Here's the full Nim.code-profile importable as profile:

{"name":"Nim","icon":"symbol-event","extensions":"[{\"identifier\":{\"id\":\"nimlang.nimlang\",\"uuid\":\"11cd9e22-9edc-411a-937c-9546d1c5b4b5\"},\"displayName\":\"nim-lang.org\"}]"}

but even using this I experience same behaviour:
nimlangserver.log stops at DBG Stopping nimsuggest for ... and process survives vscode shutdown.

This should help ruling out quite large group of possible causes

[arkanoid87]

I went print debugging langserver code

this

proc stop*(self: Nimsuggest) =
  debug "Stopping nimsuggest for ", root = self.root
  try:
    debug "A"
    self.process.kill()
    debug "B"
    self.process.close()
    debug "C"
  except Exception:
    debug "Err"
    debug getCurrentExceptionMsg()
    discard

prints this in log

DBG Stopping nimsuggest for                    root=/home/arkanoid/nim/vscode_playground/src/front/front.nim
DBG A                                         
DBG B

C is never reached, so something must be hanging inside self.process.close()

UPDATE: print debugging process.close()

import posix
import streams
proc stop*(self: Nimsuggest) =
  proc close(p: Process) =
    debug "CA ", pid=p.processID
    if poParentStreams notin p.options:
      if p.inStream != nil:
        debug "CB", pid=p.processID
        close(p.inStream)
      else:
        debug "CC", pid=p.processID
        discard close(p.inHandle)

      if p.outStream != nil:
        debug "CD", pid=p.processID
        close(p.outStream)
      else:
        debug "CE", pid=p.processID
        discard close(p.outHandle)

      if p.errStream != nil:
        debug "CF", pid=p.processID
        close(p.errStream)
      else:
        debug "CG", pid=p.processID
        discard close(p.errHandle)
    debug "CH", pid=p.processID

  debug "Stopping nimsuggest for ", root = self.root
  try:
    debug "A", pid=self.process.processID
    self.process.kill()
    debug "B", pid=self.process.processID
    self.process.close()
    debug "C", pid=self.process.processID
  except Exception:
    debug "Err", pid=self.process.processID
    debug getCurrentExceptionMsg()
    discard

log

DBG Stopping nimsuggest for                    root=/home/arkanoid/nim/vscode_playground/src/front/front.nim
DBG A                                          pid=333154
DBG B                                          pid=333154
DBG CA                                         pid=333154
DBG CC                                         pid=333154
DBG CD                                         pid=333154
DBG CF                                         pid=333154

so it seems to hang inside close(p.errStream) but

cat /proc/333154/status:

Name:   nimsuggest                                                                                                                                                                                                 
State:  Z (zombie)                                                                                                                                                                                                 
Tgid:   333154                                                                                                                                                                                                     
Ngid:   0                                                                                                                                                                                                          
Pid:    333154                                                                                                                                                                                                     
PPid:   333121                                                                                                                                                                                                     
TracerPid:      0                                                                                                                                                                                                  
Uid:    1000    1000    1000    1000                                                                                                                                                                               
Gid:    1000    1000    1000    1000                                                                                                                                                                               
FDSize: 0                                                                                                                                                                                                          
Groups: 4 20 24 27 29 30 46 122 134 135 137 140 999 1000                                                                                                                                                           
NStgid: 333154                                                                                                                                                                                                     
NSpid:  333154                                                                                                                                                                                                     
NSpgid: 332962                                                                                                                                                                                                     
NSsid:  332962                                                                                                                                                                                                     
Kthread:        0                                                                                                                                                                                                  
Threads:        1                                                                                                                                                                                                  
SigQ:   0/62820                                                                                                                                                                                                    
SigPnd: 0000000000000000                                                                                                                                                                                           
ShdPnd: 0000000000000100                                                                                                                                                                                           
SigBlk: 0000000000000000                                                                                                                                                                                           
SigIgn: 0000000000001000                                                                                                                                                                                           
SigCgt: 00000000000004aa                                                                                                                                                                                           
CapInh: 0000000000000000                                                                                                                                                                                           
CapPrm: 0000000000000000                                                                                                                                                                                           
CapEff: 0000000000000000
CapBnd: 000001ffffffffff 
CapAmb: 0000000000000000                         
NoNewPrivs:     0                                  
Seccomp:        0                                  
Seccomp_filters:        0                          
Speculation_Store_Bypass:       thread vulnerable                                                                                                                                                                  
SpeculationIndirectBranch:      conditional enabled                                                                                                                                                                
Cpus_allowed:   fff                                                                                                                                                                                                
Cpus_allowed_list:      0-11                                                                                                                                                                                       
Mems_allowed:   00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,000000
00,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001
Mems_allowed_list:      0             
voluntary_ctxt_switches:        3     
nonvoluntary_ctxt_switches:     0

seems that langserver is waiting a close(p.errStream) on a Zombie process. My knowledge says that the parent should be responsible of cleaning it up. From wikipedia:

On Unix and Unix-like computer operating systems, a zombie process or defunct process is a process that has completed execution (via the exit system call) but still has an entry in the process table: it is a process in the "terminated state". This occurs for the child processes, where the entry is still needed to allow the parent process to read its child's exit status: once the exit status is read via the wait system call, the zombie's entry is removed from the process table and it is said to be "reaped".

UPDATE2:
I might end up as the most inefficient bug seeker ever, but here's the print debug dive into close(p.errStream)

import logging
var fileLog = newFileLogger("handler.log")
addHandler(fileLog)
proc fsClose(s: Stream) =
  {.cast(raises:[]).}:
    {.cast(tags: []).}:
      info "fsClose A " & $FileStream(s).f.repr
      if FileStream(s).f != nil:
        info "fsClose B " & $FileStream(s).f.repr
        close(FileStream(s).f)
        info "fsClose C " & $FileStream(s).f.repr
        FileStream(s).f = nil
        info "fsClose D " & $FileStream(s).f.repr

when vscode is closed, the following linea are appended to handler.log:

INFO fsClose A File()
INFO fsClose B File()
INFO fsClose C File()
INFO fsClose D nil
INFO fsClose A File()
INFO fsClose B File()

strace -p<nimlangserver_pid> -s 1000000 --decode-fds

...
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG Shutting down                             \n", 47) = 47
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG stopping child nimsuggest processes       \n", 47) = 47
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG Stopping nimsuggest for                    root=/home/arkanoid/nim/vscode_playground/src/front/front.nim\n", 105) = 105
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG A                                          pid=407183\n", 58) = 58
kill(407183, SIGKILL)                   = 0
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG B                                          pid=407183\n", 58) = 58
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG CA                                         pid=407183\n", 58) = 58
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG CC                                         pid=407183\n", 58) = 58
close(18<pipe:[2017455]>)               = 0
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG CD                                         pid=407183\n", 58) = 58
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG SA                                         asd=00005592CDF05B87\n", 68) = 68
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG SB                                         asd=00005592CDF05B87\n", 68) = 68
readlink("/proc/self/exe", "/home/arkanoid/bin/nimlangserver", 1024) = 28
write(3</home/arkanoid/nim/vscode_playground/handler.log>, "INFO fsClose A File()\n", 22) = 22
readlink("/proc/self/exe", "/home/arkanoid/bin/nimlangserver", 1024) = 28
write(3</home/arkanoid/nim/vscode_playground/handler.log>, "INFO fsClose B File()\n", 22) = 22
close(20<pipe:[2017456]>)               = 0
readlink("/proc/self/exe", "/home/arkanoid/bin/nimlangserver", 1024) = 28
write(3</home/arkanoid/nim/vscode_playground/handler.log>, "INFO fsClose C File()\n", 22) = 22
readlink("/proc/self/exe", "/home/arkanoid/bin/nimlangserver", 1024) = 28
write(3</home/arkanoid/nim/vscode_playground/handler.log>, "INFO fsClose D nil\n", 19) = 19
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG CF                                         pid=407183\n", 58) = 58
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG SA                                         asd=00005592CDF05B87\n", 68) = 68
write(7</home/arkanoid/nim/vscode_playground/nimlangserver.log>, "DBG SB                                         asd=00005592CDF05B87\n", 68) = 68
readlink("/proc/self/exe", "/home/arkanoid/bin/nimlangserver", 1024) = 28
write(3</home/arkanoid/nim/vscode_playground/handler.log>, "INFO fsClose A File()\n", 22) = 22
readlink("/proc/self/exe", "/home/arkanoid/bin/nimlangserver", 1024) = 28
write(3</home/arkanoid/nim/vscode_playground/handler.log>, "INFO fsClose B File()\n", 22) = 22
futex(0x7f9f84000c50, FUTEX_WAIT_PRIVATE, 2, NULL

UPDATE3:
if I skip close but wait (reap) the child process after kill, nimlangserver shutdows correctly in vscode, even in case of multiple nimsuggest processes. I am not aware of the consequece of not closing stdin/out/err between kill and wait

proc stop*(self: Nimsuggest) =
  debug "Stopping nimsuggest for ", root = self.root
  try:
    self.process.kill()
    # self.process.close()
    dicard self.process.waitForExit()
  except Exception:
    debug getCurrentExceptionMsg()
    discard

UPDATE4:
seems to be linked to stderrThread on Nimsuggest.process.
By commenting this line:

langserver/suggestapi.nim

Line 360 in 3eb83da

createThread(stderrThread, logStderr, (root: root, process: result.process))

leaving proc stop(...) as-is, the infinite wait doesn't happen.
Maybe this way to handle stdErr is not correct?

langserver/suggestapi.nim

Line 238 in 3eb83da

proc logStderr(param: tuple[root: string, process: Process]) {.thread.} =

UPDATE5:

I can confirm that the line that prevents nimlangserver to close stderr of Zombified nimsuggest process is:

langserver/suggestapi.nim

Line 240 in 3eb83da

var line = param.process.errorStream.readLine

I've tried some educated guess solution, but this problem goes beyond my knowledge of pipes, futexes, and cross-platform IPC I/O in general. Also I see some hacks I don't quite understand.
I'll fallback to NimLsp which avoids this problem completely while waiting this problem to be solved, as it leaks >100MB ram on each VSCode run, depending on the project complexity/import tree.

[nickysn]

Hmm, it's possible that the logStderr is causing this. It does a blocking read on the fd in another thread. While this blocking call is in progress, we call close() on the fd in the main thread. man close states the following about doing this:

Multithreaded processes and close()
It is probably unwise to close file descriptors while they may be in use by system calls in other threads in the same process. Since a file descriptor may be reused, there are some obscure race conditions that may cause un‐
intended side effects.

When dealing with sockets, you have to be sure that there is no recv(2) still blocking on it on another thread, otherwise it might block forever, since no more messages will be send via the socket. Be sure to use shutdown(2)
to shut down all parts the connection before closing the socket.

Furthermore, consider the following scenario where two threads are performing operations on the same file descriptor:

(1) One thread is blocked in an I/O system call on the file descriptor. For example, it is trying to write(2) to a pipe that is already full, or trying to read(2) from a stream socket which currently has no available data.

(2) Another thread closes the file descriptor.

The behavior in this situation varies across systems. On some systems, when the file descriptor is closed, the blocking system call returns immediately with an error.

On Linux (and possibly some other systems), the behavior is different: the blocking I/O system call holds a reference to the underlying open file description, and this reference keeps the description open until the I/O system
call completes. (See open(2) for a discussion of open file descriptions.) Thus, the blocking system call in the first thread may successfully complete after the close() in the second thread.

So, it looks like it could cause some nasty race condition. However, the documented behavior under Linux should not cause close() to block. And I'm not experiencing this under Fedora 39 (with kernel-6.7.4-200.fc39.x86_64 and glibc-2.38-16.fc39.x86_64). Could it be something Ubuntu-specific? I need to try this in a VM. Another question: Does it happen on every project, or just this one? Is there something special about https://github.com/arkanoid87/nim_vscode_playground or does it also happen in just an empty dir with hello.nim like this:

echo "Hello, world!"

?

[nickysn]

Same thing happens on Windows 11

Please file a separate bug report for Windows, with the exact steps to reproduce. Include, at least, Nim and nimsuggest version, how did you install them, VS Code version, vscode-nim plugin version, other plugins that you have installed, your VS Code config file, the project you're testing this on, etc.

[arkanoid87]

Hmm, it's possible that the logStderr is causing this. It does a blocking read on the fd in another thread. While this blocking call is in progress, we call close() on the fd in the main thread. man close states the following about doing this:

Multithreaded processes and close()
It is probably unwise to close file descriptors while they may be in use by system calls in other threads in the same process. Since a file descriptor may be reused, there are some obscure race conditions that may cause un‐
intended side effects.
When dealing with sockets, you have to be sure that there is no recv(2) still blocking on it on another thread, otherwise it might block forever, since no more messages will be send via the socket. Be sure to use shutdown(2)
to shut down all parts the connection before closing the socket.
Furthermore, consider the following scenario where two threads are performing operations on the same file descriptor:
(1) One thread is blocked in an I/O system call on the file descriptor. For example, it is trying to write(2) to a pipe that is already full, or trying to read(2) from a stream socket which currently has no available data.
(2) Another thread closes the file descriptor.
The behavior in this situation varies across systems. On some systems, when the file descriptor is closed, the blocking system call returns immediately with an error.
On Linux (and possibly some other systems), the behavior is different: the blocking I/O system call holds a reference to the underlying open file description, and this reference keeps the description open until the I/O system
call completes. (See open(2) for a discussion of open file descriptions.) Thus, the blocking system call in the first thread may successfully complete after the close() in the second thread.

So, it looks like it could cause some nasty race condition. However, the documented behavior under Linux should not cause close() to block. And I'm not experiencing this under Fedora 39 (with kernel-6.7.4-200.fc39.x86_64 and glibc-2.38-16.fc39.x86_64). Could it be something Ubuntu-specific? I need to try this in a VM. Another question: Does it happen on every project, or just this one? Is there something special about https://github.com/arkanoid87/nim_vscode_playground or does it also happen in just an empty dir with hello.nim like this:

echo "Hello, world!"

?

it happens even with minimal project:

$ mkdir minimal
$ cd minimal
$ echo 'echo "hello world!"' > main.nim
$ code .
# (quit vscode)
$ ps -aux | grep nimsuggest
arkanoid      319123  0.0  0.0      0     0 ?        Z    22:23   0:00 [nimsuggest] <defunct>
arkanoid      319126  0.2  0.1  41272 32384 ?        Sl   22:23   0:00 /home/arkanoid/.choosenim/toolchains/nim-2.0.2/bin/nimsuggest /home/arkanoid/nim/minimal/main.nim --v4 --autobind --clientProcessId:319105
arkanoid      319753  0.0  0.0   9220  2432 pts/1    S+   22:25   0:00 grep --color=auto nimsuggest
$ ps -aux | grep nimlangserver
arkanoid      319105  0.0  0.0 218328 11948 ?        Sl   22:23   0:00 /home/arkanoid/.nimble/pkgs2/nimlangserver-1.2.0-95de85fae4485dcd850ada31e200d15671a00c4a/nimlangserver --stdio
arkanoid      319846  0.0  0.0   9220  2432 pts/1    S+   22:28   0:00 grep --color=auto nimlangserver

[nickysn]

Very strange. Tried this in a VM under Ubuntu 22.04.3 LTS (with latest updates) and I still couldn't reproduce it. What is your kernel version? The close and read calls are actually syscalls of the kernel, so it could be kernel version-related.

[arkanoid87]

$ uname -a
Linux 6.5.0-17-generic #17~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Tue Jan 16 14:32:32 UTC 2 x86_64 x86_64 x86_64 GNU/Linux

from

linux-image-6.5.0-17-generic/jammy-updates,jammy-security,now 6.5.0-17.17~22.04.1 amd64 [installed,automatic]

I'm gonna test on a different machine, as this is getting spooky