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

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

Closed
soulomoon opened this issue Mar 25, 2024 · 4 comments
Closed

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

soulomoon opened this issue Mar 25, 2024 · 4 comments
Labels
component: lsp flaky test type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc..

Comments

@soulomoon
Copy link
Collaborator

soulomoon commented Mar 25, 2024

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 soulomoon added type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc.. status: needs triage component: lsp flaky test and removed status: needs triage labels Mar 25, 2024
@soulomoon
Copy link
Collaborator Author

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
Copy link
Collaborator Author

soulomoon commented Mar 25, 2024

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 soulomoon changed the title Tests that are blocked for 3 second waitting for the server to shutdown Tests that are blocked for 3 second waitting for the server to exit Mar 25, 2024
@soulomoon
Copy link
Collaborator Author

soulomoon commented Apr 13, 2024

It should be fixed when the new lsp realease with haskell/lsp#567 merged

@soulomoon
Copy link
Collaborator Author

Fixed by #4166

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
component: lsp flaky test type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc..
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant