search

haskell / haskell-language-server

Official haskell ide support via language server (LSP). Successor of ghcide & haskell-ide-engine.
Apache License 2.0
2.71k stars 368 forks source link

Tests that are blocked for 3 second waitting for the server to exit #4152

Closed soulomoon closed 5 months ago

soulomoon commented 7 months ago

We have some tests that are blocked for 3 second waitting for the shutdown of the server. https://github.com/soulomoon/haskell-language-server/blob/693f2a13fdc9319ed4f85d1ac7e2c45548888a29/hls-test-utils/src/Test/Hls.hs#L644-L645

For example in this test https://github.com/soulomoon/haskell-language-server/blob/693f2a13fdc9319ed4f85d1ac7e2c45548888a29/plugins/hls-refactor-plugin/test/Main.hs#L80

we can see the bug:

cabal test haskell-language-server:test:hls-refactor-plugin-tests --test-options="-p /refactor/"

My guess is that

~~The SMethod_Shutdown is sent to the server at the end of runSessionWithHandles It seems for this case the shutdown handler SMethod_Shutdown is not set up even after runSessionWithHandles is done. I added a sleep 0.1 to the test to wait for the setup, then the server is closed as normal.~~

soulomoon commented 7 months ago 
Running 1 test suites...
Test suite hls-refactor-plugin-tests: RUNNING...
refactor
  initialize response capabilities
       code action:     2024-03-25T18:02:48.974943Z | Info | Heap statistics are not enabled (RTS option -T is needed)
2024-03-25T18:02:48.979262Z | Info | Starting LSP server...
  If you are seeing this in a terminal, you probably should have run WITHOUT the --lsp option!
  PluginIds: [ ghcide-completions-1
             , ghcide-completions
             , ghcide-code-actions-bindings
             , ghcide-hover-and-symbols
             , ghcide-code-actions-type-signatures
             , test
             , ghcide-code-actions-fill-holes
             , block-command
             , ghcide-type-lenses
             , ghcide-code-actions-imports-exports
             , ghcide-core ]
2024-03-25T18:02:48.981857Z | Info | Starting server
2024-03-25T18:02:48.984059Z | Debug | LSP: set new config: {
  "cabalFormattingProvider": "cabal-gild",
  "checkParents": "CheckOnSave",
  "checkProject": true,
  "formattingProvider": "ormolu",
  "maxCompletions": 40,
  "plugin": {  }
}
2024-03-25T18:02:48.985261Z | Info | Started LSP server in 0.01s
2024-03-25T18:02:49.170888Z | Debug | ghc --print-libdir
2024-03-25T18:02:49.172139Z | Debug | Setting initial dynflags...
2024-03-25T18:02:49.172201Z | Debug | shouldRunSubset: True
2024-03-25T18:02:49.172318Z | Debug | Initializing exports map from hiedb
2024-03-25T18:02:49.172404Z | Info | Registering IDE configuration: IdeConfiguration {workspaceFolders = fromList [NormalizedUri 1509901739996420084 "file:///private/var/folders/36/_743psv11gv2wrj9dclrpd500000gn/T/extra-dir-67437986947"], clientSettings = hashed (Just (Object (fromList [("haskell",Object (fromList [("cabalFormattingProvider",String "cabal-gild"),("checkParents",String "CheckOnSave"),("checkProject",Bool True),("formattingProvider",String "ormolu"),("maxCompletions",Number 40.0),("plugin",Object (fromList []))]))])))}
2024-03-25T18:02:49.173349Z | Debug | Received shutdown message
2024-03-25T18:02:49.173682Z | Debug | LSP: set new config: {
  "cabalFormattingProvider": "cabal-gild",
  "checkParents": "CheckOnSave",
  "checkProject": true,
  "formattingProvider": "ormolu",
  "maxCompletions": 40,
  "plugin": {  }
}
2024-03-25T18:02:49.173755Z | Debug | Configuration changed: Config {checkParents = CheckOnSave, checkProject = True, formattingProvider = "ormolu", cabalFormattingProvider = "cabal-gild", maxCompletions = 40, plugins = fromList []}
2024-03-25T18:02:49.178554Z | Info | Reactor thread stopped
Server does not exit in 3s, canceling the async task...
Finishing canceling (took 0.00ss)
                        OK
       execute command: OK

All 2 tests passed (3.21s)
Test suite hls-refactor-plugin-tests: PASS
Test suite logged to:
/Volumes/src/haskell-language-server/dist-newstyle/build/aarch64-osx/ghc-9.8.2/haskell-language-server-2.7.0.0/t/hls-refactor-plugin-tests/test/haskell-language-server-2.7.0.0-hls-refactor-plugin-tests.log
1 of 1 test suites (1 of 1 test cases) passed.

vs

❯ HLS_TEST_LOG_STDERR=1 cabal test haskell-language-server:test:hls-refactor-plugin-tests --test-options="-p /refactor/"
Build profile: -w ghc-9.8.2 -O1
In order, the following will be built (use -v for more details):
 - haskell-language-server-2.7.0.0 (test:hls-refactor-plugin-tests) (ephemeral targets)
Preprocessing test suite 'hls-refactor-plugin-tests' for haskell-language-server-2.7.0.0..
Building test suite 'hls-refactor-plugin-tests' for haskell-language-server-2.7.0.0..
Running 1 test suites...
Test suite hls-refactor-plugin-tests: RUNNING...
refactor
  initialize response capabilities
       code action:     2024-03-25T18:01:49.861169Z | Info | Heap statistics are not enabled (RTS option -T is needed)
2024-03-25T18:01:49.877917Z | Info | Starting LSP server...
  If you are seeing this in a terminal, you probably should have run WITHOUT the --lsp option!
  PluginIds: [ ghcide-completions-1
             , ghcide-completions
             , ghcide-code-actions-bindings
             , ghcide-hover-and-symbols
             , ghcide-code-actions-type-signatures
             , test
             , ghcide-code-actions-fill-holes
             , block-command
             , ghcide-type-lenses
             , ghcide-code-actions-imports-exports
             , ghcide-core ]
2024-03-25T18:01:49.881566Z | Info | Starting server
2024-03-25T18:01:49.891787Z | Debug | LSP: set new config: {
  "cabalFormattingProvider": "cabal-gild",
  "checkParents": "CheckOnSave",
  "checkProject": true,
  "formattingProvider": "ormolu",
  "maxCompletions": 40,
  "plugin": {  }
}
2024-03-25T18:01:49.897581Z | Info | Started LSP server in 0.02s
2024-03-25T18:01:50.231054Z | Debug | ghc --print-libdir
2024-03-25T18:01:50.233419Z | Debug | Setting initial dynflags...
2024-03-25T18:01:50.233462Z | Debug | shouldRunSubset: True
2024-03-25T18:01:50.233541Z | Debug | Initializing exports map from hiedb
2024-03-25T18:01:50.233820Z | Info | Registering IDE configuration: IdeConfiguration {workspaceFolders = fromList [NormalizedUri (-3873774377856205578) "file:///private/var/folders/36/_743psv11gv2wrj9dclrpd500000gn/T/extra-dir-54275890947"], clientSettings = hashed (Just (Object (fromList [("haskell",Object (fromList [("cabalFormattingProvider",String "cabal-gild"),("checkParents",String "CheckOnSave"),("checkProject",Bool True),("formattingProvider",String "ormolu"),("maxCompletions",Number 40.0),("plugin",Object (fromList []))]))])))}
2024-03-25T18:01:50.243506Z | Debug | Shake session initialized
2024-03-25T18:01:50.243528Z | Debug | Done initializing exports map from hiedb. Size: 0
2024-03-25T18:01:50.337029Z | Debug | Received shutdown message
2024-03-25T18:01:50.337201Z | Debug | Finished build session
AsyncCancelled
2024-03-25T18:01:50.337316Z | Debug | LSP: set new config: {
  "cabalFormattingProvider": "cabal-gild",
  "checkParents": "CheckOnSave",
  "checkProject": true,
  "formattingProvider": "ormolu",
  "maxCompletions": 40,
  "plugin": {  }
}
2024-03-25T18:01:50.338164Z | Info | Reactor thread stopped
2024-03-25T18:01:50.338384Z | Debug | Configuration changed: Config {checkParents = CheckOnSave, checkProject = True, formattingProvider = "ormolu", cabalFormattingProvider = "cabal-gild", maxCompletions = 40, plugins = fromList []}
2024-03-25T18:01:50.338507Z | Debug | Restarting build session due to config change
Action Queue: []
Keys: [GetClientSettings; ]
Aborting previous build session took 0.00s
2024-03-25T18:01:50.338942Z | Debug | Received exit message
                        OK
       execute command: OK

All 2 tests passed (0.49s)
Test suite hls-refactor-plugin-tests: PASS
Test suite logged to:
/Volumes/src/haskell-language-server/dist-newstyle/build/aarch64-osx/ghc-9.8.2/haskell-language-server-2.7.0.0/t/hls-refactor-plugin-tests/test/haskell-language-server-2.7.0.0-hls-refactor-plugin-tests.log
1 of 1 test suites (1 of 1 test cases) passed.
soulomoon commented 7 months ago

It is because setSomethingModified is called after shutdown. It hangs in the setSomethingModified during configuration change. It is blocking the further handling of Exit, the exit is sent and never received. I am working out a solution to avoid the situation.

setSomethingModified is called after the shutdown. We can put configuration change into the reactor thread to avoid the situation.

soulomoon commented 6 months ago

It should be fixed when the new lsp realease with https://github.com/haskell/lsp/pull/567 merged

soulomoon commented 5 months ago

Fixed by #4166