Run plugins' test suites with server in the same process #1628

berberman · 2021-03-27T15:15:27Z

Following #1617

Hope this would make tests more stable

berberman · 2021-03-28T10:18:50Z

Tests on Windows seemd got stuck again:
https://github.com/haskell/haskell-language-server/pull/1628/checks?check_run_id=2211603744
https://github.com/haskell/haskell-language-server/pull/1628/checks?check_run_id=2211603749

Isn't it enough to set shakeThreads to 2?

hls-test-utils/src/Test/Hls.hs

pepeiborra · 2021-03-28T18:14:11Z

Tests on Windows seemd got stuck again:
https://github.com/haskell/haskell-language-server/pull/1628/checks?check_run_id=2211603744
https://github.com/haskell/haskell-language-server/pull/1628/checks?check_run_id=2211603749

Isn't it enough to set shakeThreads to 2?

You also need to build with --threaded

berberman · 2021-03-29T02:46:40Z

Tests on Windows seemd got stuck again:
https://github.com/haskell/haskell-language-server/pull/1628/checks?check_run_id=2211603744
https://github.com/haskell/haskell-language-server/pull/1628/checks?check_run_id=2211603749
Isn't it enough to set shakeThreads to 2?

You also need to build with --threaded

Mmm, -threaded is already here:

haskell-language-server/plugins/hls-eval-plugin/hls-eval-plugin.cabal

Lines 95 to 100 in 1f12a61

    
           test-suite tests 
        
             type:             exitcode-stdio-1.0 
        
             default-language: Haskell2010 
        
             hs-source-dirs:   test 
        
             main-is:          Main.hs 
        
             ghc-options:      -threaded -rtsopts -with-rtsopts=-N

berberman · 2021-03-30T04:41:42Z

So far, tests of plugins on linux and macOS look great, but on Windows, they seem to hang100%. I don't have Windows machine with development environment setup, no idea how to debug this.

jneira · 2021-03-30T05:33:38Z

I'll try to take a look in my local win 10

jneira · 2021-03-31T05:20:05Z

Unfortunately tests pass in my local windows 10, after a first try with some resource vanished but no stuck. 😟

berberman · 2021-03-31T08:13:30Z

Ugh, it's still getting stuck... BTW definition and hover tests of ghcide is fairly unstable, and it even fails on my machine constantly: #1626 (comment)

hls-test-utils/src/Test/Hls.hs

pepeiborra · 2021-03-31T19:58:29Z

Unfortunately tests pass in my local windows 10, after a first try with some resource vanished but no stuck. 😟

But this is the same problem that CI shows, isn't it? Tests are not stuck, they are failing in Windows GHC 8.10.4. "resource vanished - broken pipe" means that HLS stopped running. Either it was killed, it crashed, or it decided to exit on its own.

Why is HLS crashing in Windows 8.10.4 all of a sudden? Has anything changed?

jneira · 2021-03-31T21:35:02Z

But this is the same problem that CI shows, isn't it?

Yeah, i thought they stuck without no response until a ci timeout, without reviewing the logs,thanks for pointing it out.
The symtomps are similar locally but the situation is much worse in ci, locally i got three errors in a cold first run and it passed in the second one.

Why is HLS crashing in Windows 8.10.4 all of a sudden? Has anything changed?

It is failing since some time ago, although it seems in this pr is worse. I have been reviewing the gh actions and dont see a pattern. There are recent builds with succesful test run at first like https://github.com/haskell/haskell-language-server/runs/2197782538?check_suite_focus=true
Being transient errors and the differences between ci and my local machine make a bisect is hard 😟

berberman · 2021-04-01T04:25:12Z

Sometimes a dying server (after the test session finished successfully) throws this error:

tests.exe: Control.Concurrent.Extra.signalBarrier, attempt to signal a barrier that has already been signaled
CallStack (from HasCallStack):
  errorIO, called at src\Control\Concurrent\Extra.hs:196:16 in extra-1.7.9-1fb0534e9d12add2b941eefeb5d3e9bbdea5a70c:Control.Concurrent.Extra
  signalBarrier, called at src\Development\IDE\LSP\LanguageServer.hs:64:16 in ghcide-1.1.0.0-inplace:Development.IDE.LSP.LanguageServer

haskell-language-server/ghcide/src/Development/IDE/LSP/LanguageServer.hs

Lines 59 to 64 in d60dee0

    
           -- These barriers are signaled when the threads reading from these chans exit. 
        
           -- This should not happen but if it does, we will make sure that the whole server 
        
           -- dies and can be restarted instead of losing threads silently. 
        
           clientMsgBarrier <- newBarrier 
        
           -- Forcefully exit 
        
           let exit = signalBarrier clientMsgBarrier ()

Does it mean the server received two exit messages?

pepeiborra · 2021-04-01T07:20:56Z

But this is the same problem that CI shows, isn't it?

Yeah, i thought they stuck without no response until a ci timeout, without reviewing the logs,thanks for pointing it out.
The symtomps are similar locally but the situation is much worse in ci, locally i got three errors in a cold first run and it passed in the second one.

Why is HLS crashing in Windows 8.10.4 all of a sudden? Has anything changed?

It is failing since some time ago, although it seems in this pr is worse. I have been reviewing the gh actions and dont see a pattern. There are recent builds with succesful test run at first like https://github.com/haskell/haskell-language-server/runs/2197782538?check_suite_focus=true
Being transient errors and the differences between ci and my local machine make a bisect is hard 😟

This PR didn't make any changes to the ghcide test suite, so I don't see the connection. Unfortunately master has the getting-stuck problem which means we cannot see if the Windows issue is specific to this PR or not

pepeiborra · 2021-04-01T07:23:06Z

Sometimes a dying server (after the test session finished successfully) throws this error:
tests.exe: Control.Concurrent.Extra.signalBarrier, attempt to signal a barrier that has already been signaled
CallStack (from HasCallStack):
  errorIO, called at src\Control\Concurrent\Extra.hs:196:16 in extra-1.7.9-1fb0534e9d12add2b941eefeb5d3e9bbdea5a70c:Control.Concurrent.Extra
  signalBarrier, called at src\Development\IDE\LSP\LanguageServer.hs:64:16 in ghcide-1.1.0.0-inplace:Development.IDE.LSP.LanguageServer
haskell-language-server/ghcide/src/Development/IDE/LSP/LanguageServer.hs

Lines 59 to 64 in d60dee0

-- These barriers are signaled when the threads reading from these chans exit.

-- This should not happen but if it does, we will make sure that the whole server

-- dies and can be restarted instead of losing threads silently.

clientMsgBarrier <- newBarrier

-- Forcefully exit

let exit = signalBarrier clientMsgBarrier ()

Does it mean the server received two exit messages?

Yes, I think so. Perhaps this is a new feature of lsp-test.

Great find! Please fix the crash by replacing the Barrier with a plain MVar and let's see if that unblocks the test suite!

berberman · 2021-04-01T08:10:29Z

One difference between local machine and Windows CI I noticed (by checking lsp messages log one by one) was that in CI, there were no hiedb related messages sent from the server, such as ghcide/reference/ready, Finished indexing 1 files.

berberman · 2021-04-01T08:14:56Z

Sometimes a dying server (after the test session finished successfully) throws this error:
tests.exe: Control.Concurrent.Extra.signalBarrier, attempt to signal a barrier that has already been signaled
CallStack (from HasCallStack):
  errorIO, called at src\Control\Concurrent\Extra.hs:196:16 in extra-1.7.9-1fb0534e9d12add2b941eefeb5d3e9bbdea5a70c:Control.Concurrent.Extra
  signalBarrier, called at src\Development\IDE\LSP\LanguageServer.hs:64:16 in ghcide-1.1.0.0-inplace:Development.IDE.LSP.LanguageServer
haskell-language-server/ghcide/src/Development/IDE/LSP/LanguageServer.hs

Lines 59 to 64 in d60dee0

-- These barriers are signaled when the threads reading from these chans exit.

-- This should not happen but if it does, we will make sure that the whole server

-- dies and can be restarted instead of losing threads silently.

clientMsgBarrier <- newBarrier

-- Forcefully exit

let exit = signalBarrier clientMsgBarrier ()

Does it mean the server received two exit messages?
Yes, I think so. Perhaps this is a new feature of lsp-test.

Great find! Please fix the crash by replacing the Barrier with a plain MVar and let's see if that unblocks the test suite!

But according to the lsp messages log, the client sends exactly one exit message 🤔

Anyway, I don't see the reason that we need Barrier instead of MVar -- being signalled more than one time should be OK as well.

wz1000 · 2021-04-01T16:00:19Z

You might want to investigate/patch lsp-test. I believe the resource vanished error comes from this line: https://github.com/haskell/lsp/blob/6dd6ad630ddb4a08a2bbcd6f71588f0864a555b6/lsp-test/src/Language/LSP/Test/Session.hs#L440

It might be good to add a catch there, or at least print out more information for debugging (like the message we are trying to send).

berberman · 2021-04-02T04:51:47Z

hls-test-utils/src/Test/Hls.hs

+  timeout 3 (wait server) >>= \case
+    Just () -> pure ()
+    Nothing -> putStrLn "Server does not exit on time, canceling the async task..." >> cancel server


Tests on Windows passed with this. We should investigate why the server didn't exit properly.

I'm just looking at the exit code in ghcide and I think it might be time to update it. I'm not sure that the waitAnyCancel construction is needed any more, and it could be hiding exceptions coming from the lsp library:

haskell-language-server/ghcide/src/Development/IDE/LSP/LanguageServer.hs

Lines 114 to 120 in a4dee2d

void $ waitAnyCancel =<< traverse async

[ void $ LSP.runServerWithHandles

inH

outH

serverDefinition

, void $ waitBarrier clientMsgBarrier

]

EDIT: according to the docs, exceptions will be re-thrown to the parent thread, so maybe it's harmless

Another problem is that defaultMain does not call setupLogger so we might be missing lsp errors

haskell-language-server/ghcide/src/Development/IDE/LSP/LanguageServer.hs

Lines 59 to 62 in 6d1f1a5

-- These barriers are signaled when the threads reading from these chans exit.

-- This should not happen but if it does, we will make sure that the whole server

-- dies and can be restarted instead of losing threads silently.

clientMsgBarrier <- newBarrier

These comments match the old code:

haskell-language-server/ghcide/src/Development/IDE/LSP/Server.hs

Lines 73 to 99 in fa671cb

void $ waitAnyCancel =<< traverse async

[ void $ LSP.runWithHandles

stdin

newStdout

( const $ Right ()

, handleInit (signalBarrier clientMsgBarrier ()) clientMsgChan

)

(handlers clientMsgChan)

options

Nothing

, void $ waitBarrier clientMsgBarrier

]

where

handleInit :: IO () -> TChan LSP.FromClientMessage -> LSP.LspFuncs () -> IO (Maybe LSP.ResponseError)

handleInit exitClientMsg clientMsgChan lspFuncs@LSP.LspFuncs{..} = do

Handlers{..} <- getHandlers lspFuncs

let requestHandler' (req, reqId) = requestHandler

(\res -> ResponseMessage "2.0" (responseId reqId) (Just res) Nothing)

(\err -> ResponseMessage "2.0" (responseId reqId) Nothing (Just $ ResponseError err "" Nothing))

req

_ <- flip forkFinally (const exitClientMsg) $ forever $ do

msg <- atomically $ readTChan clientMsgChan

case convClientMsg msg of

Nothing -> Logger.logSeriousError loggerH $ "Unknown client msg: " <> T.pack (show msg)

Just (Left notif) -> notificationHandler notif

Just (Right req) -> sendFunc =<< requestHandler' req

pure Nothing

but now this barrier will be signalled when the server receives exit message instead.

I think we could try removing the waitAnyCancel.

Yes, now we signal the barrier from two places - the exit handler and also if the initialisation fails, which probably explains the error that you were seeing earlier.

I'm not convinced that removing it will actually fix anything. runServerWithHandles doesn't actually exit until the input stream is closed, and I don't know whether lsp-test closes the stream until the server exits

It seems that lsp-test won't close the handle for us (in our case mServerProc is Nothing):

haskell-language-server/lsp-test/src/Language/LSP/Test/Session.hs

Lines 282 to 294 in 7a2ff3a

let cleanup

| Just sp <- mServerProc = do

-- Give the server some time to exit cleanly

-- It makes the server hangs in windows so we have to avoid it

#ifndef mingw32_HOST_OS

timeout msgTimeoutMs (waitForProcess sp)

#endif

cleanupProcess (Just serverIn, Just serverOut, Nothing, sp)

| otherwise = pure ()

finally (timeout msgTimeoutMs (runSession' exitServer))

-- Make sure to kill the listener first, before closing

-- handles etc via cleanupProcess

(killThread tid >> cleanup)

But I didn't find any manual close in the test of lsp-test. Maybe @wz1000 could help?

I'm pretty sure the handle closes when the server exits.

The handle closes when the server exits, sure, but as I said runServerWithHandles doesn't exit until the stream ends, so it won't exit.

berberman · 2021-04-02T09:49:13Z

I observed some snippets from debug log, like this:

[Debug] Finishing build session(exception: Error when running Shake build system:
thread blocked indefinitely in an STM transaction
)
[Debug] Finishing build session(exception: Error when running Shake build system:
[Debug] Finishing build session(exception: Error when running Shake build system:
[Debug] Finishing build session(exception: Error when running Shake build system:
thread blocked indefinitely in an STM transaction
thread blocked indefinitely in an STM transaction
thread blocked indefinitely in an STM transaction
)))

pepeiborra · 2021-04-02T10:01:04Z

I observed some snippets from debug log, like this:

[Debug] Finishing build session(exception: Error when running Shake build system:
thread blocked indefinitely in an STM transaction
)
[Debug] Finishing build session(exception: Error when running Shake build system:
[Debug] Finishing build session(exception: Error when running Shake build system:
[Debug] Finishing build session(exception: Error when running Shake build system:
thread blocked indefinitely in an STM transaction
thread blocked indefinitely in an STM transaction
thread blocked indefinitely in an STM transaction
)))

That is not necessarily an issue, helper threads like the reactor thread or the hiedb thread would fail like that when the main thread exits the lsp loop and no longer keeps a reference to the shared state

hls-test-utils/src/Test/Hls.hs

berberman · 2021-04-03T05:58:48Z

The server sends "Finishing build session..." using notifyTestingLogMessage when a worker exits, but in our case, the input stream has been closed. Thus, calling shakeShut in exit message handler results in hPutBuf: resource vanished (Broken pipe).

haskell-language-server/ghcide/src/Development/IDE/Core/Shake.hs

Lines 726 to 735 in 252c500

    
           workRun restore = withSpan "Shake session" $ \otSpan -> do 
        
             let acts' = pumpActionThread otSpan : map (run otSpan) (reenqueued ++ acts) 
        
             res <- try @SomeException (restore $ shakeRunDatabase shakeDb acts') 
        
             let res' = case res of 
        
                         Left e  -> "exception: " <> displayException e 
        
                         Right _ -> "completed" 
        
             let msg = T.pack $ "Finishing build session(" ++ res' ++ ")" 
        
             return $ do 
        
                 logDebug logger msg 
        
                 notifyTestingLogMessage extras msg

haskell-language-server/ghcide/src/Development/IDE/Core/Shake.hs

Lines 673 to 677 in 252c500

    
           notifyTestingLogMessage :: ShakeExtras -> T.Text -> IO () 
        
           notifyTestingLogMessage extras msg = do 
        
               (IdeTesting isTestMode) <- optTesting <$> getIdeOptionsIO extras 
        
               let notif = LSP.LogMessageParams LSP.MtLog msg 
        
               when isTestMode $ mRunLspT (lspEnv extras) $ LSP.sendNotification LSP.SWindowLogMessage notif

And it seems that the server still reports progress after shutting down the shake. Should we call stopProgressReporting before cancelShakeSession in shakeShut?

haskell-language-server/ghcide/src/Development/IDE/Core/Shake.hs

Lines 618 to 624 in 252c500

    
           shakeShut :: IdeState -> IO () 
        
           shakeShut IdeState{..} = withMVar shakeSession $ \runner -> do 
        
               -- Shake gets unhappy if you try to close when there is a running 
        
               -- request so we first abort that. 
        
               void $ cancelShakeSession runner 
        
               shakeClose 
        
               stopProgressReporting

Also, is it possible to disable lsp capabilities when we want server die?

A piece of log from Windows CI:

brittany
Starting LSP server...
If you are seeing this in a terminal, you probably should have run ghcide WITHOUT the --lsp option!
Started LSP server in 0.08s
setInitialDynFlags cradle: Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
Output from setting up the cradle Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
lsp:Got EOF, exiting 1 ...

warning: LF will be replaced by CRLF in C:/Users/runneradmin/AppData/Local/Temp/BriA841.actual.
The file will have its original line endings in your working directory
Starting LSP server...
  formats a document with LF endings:   OK (0.79s)
If you are seeing this in a terminal, you probably should have run ghcide WITHOUT the --lsp option!
Started LSP server in 0.00s
  formats a document with CRLF endings: IO Exception: clientOut:
<file descriptor: 6>: hPutBuf: resource vanished (Broken pipe)
{"method":"window/logMessage","params":{"message":"Finishing build session(exception: AsyncCancelled)","type":4},"jsonrpc":"2.0"}
IO Exception: clientOut:
<file descriptor: 6>: hPutBuf: resource vanished (Broken pipe)
{"method":"window/logMessage","params":{"message":"Restarting build session (aborting the previous one took 0.00s)","type":4},"jsonrpc":"2.0"}
IO Exception: clientOut:
<file descriptor: 6>: hPutBuf: resource vanished (Broken pipe)
{"method":"window/logMessage","params":{"message":"Finishing build session(exception: AsyncCancelled)","type":4},"jsonrpc":"2.0"}
IO Exception: clientOut:
<file descriptor: 6>: hPutBuf: resource vanished (Broken pipe)
{"method":"$/progress","params":{"token":"14","value":{"message":"2/2","kind":"report"}},"jsonrpc":"2.0"}
setInitialDynFlags cradle: Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
Output from setting up the cradle Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
lsp:Got EOF, exiting 1 ...

warning: LF will be replaced by CRLF in C:/Users/runneradmin/AppData/Local/Temp/BriB274.actual.
The file will have its original line endings in your working directory
Starting LSP server...
OK (2.61s)
If you are seeing this in a terminal, you probably should have run ghcide WITHOUT the --lsp option!
Started LSP server in 0.00s
setInitialDynFlags cradle: Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
Output from setting up the cradle Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
  formats a range with LF endings:      IO Exception: clientOut:
<file descriptor: 9>: hPutBuf: resource vanished (Broken pipe)
{"method":"window/logMessage","params":{"message":"Finishing build session(exception: AsyncCancelled)","type":4},"jsonrpc":"2.0"}
IO Exception: clientOut:
<file descriptor: 9>: hPutBuf: resource vanished (Broken pipe)
{"method":"window/logMessage","params":{"message":"Restarting build session (aborting the previous one took 2.03s)","type":4},"jsonrpc":"2.0"}
IO Exception: clientOut:
<file descriptor: 9>: hPutBuf: resource vanished (Broken pipe)
{"method":"window/logMessage","params":{"message":"Finishing build session(exception: AsyncCancelled)","type":4},"jsonrpc":"2.0"}
IO Exception: clientOut:
<file descriptor: 9>: hPutBuf: resource vanished (Broken pipe)
{"method":"$/progress","params":{"token":"37","value":{"message":"2/2","kind":"report"}},"jsonrpc":"2.0"}
lsp:Got EOF, exiting 1 ...

warning: LF will be replaced by CRLF in C:/Users/runneradmin/AppData/Local/Temp/BriB4B9.actual.
The file will have its original line endings in your working directory
Starting LSP server...
OK (0.57s)
If you are seeing this in a terminal, you probably should have run ghcide WITHOUT the --lsp option!
Started LSP server in 0.00s
setInitialDynFlags cradle: Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
Output from setting up the cradle Cradle {cradleRootDir = "D:\\a\\haskell-language-server\\haskell-language-server\\plugins\\hls-brittany-plugin\\test\\testdata", cradleOptsProg = CradleAction: Default}
lsp:Got EOF, exiting 1 ...

warning: LF will be replaced by CRLF in plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.formatted_range.hs.
The file will have its original line endings in your working directory
warning: LF will be replaced by CRLF in C:/Users/runneradmin/AppData/Local/Temp/BriB6AF.actual.
The file will have its original line endings in your working directory
  formats a range with CRLF endings:    OK (0.51s)

All 4 tests passed (4.47s)
Test suite tests: PASS
Test suite logged to:
D:\a\haskell-language-server\haskell-language-server\dist-newstyle\build\x86_64-windows\ghc-8.10.4\hls-brittany-plugin-1.0.0.0\t\tests\test\hls-brittany-plugin-1.0.0.0-tests.log
1 of 1 test suites (1 of 1 test cases) passed.

pepeiborra · 2021-04-03T08:47:09Z

shakeShut already calls progress reporting - could you try to reorder the statements so that it calls it first?

This output is caused by lsp-test closing the stream immediately in Windows, whereas it waits for the server to exit in Linux:

https://github.com/haskell/lsp/blob/6dd6ad630ddb4a08a2bbcd6f71588f0864a555b6/lsp-test/src/Language/LSP/Test/Session.hs#L283-L288

So it's probably not a big deal

hls-test-utils/src/Test/Hls.hs

…nto plugin-tests2

berberman · 2021-04-04T08:21:14Z

The barrier did be signaled two times. Is this exit what we expected?

[Error] Fatal error in server thread: thread blocked indefinitely in an MVar operation
tests: Control.Concurrent.Extra.signalBarrier, attempt to signal a barrier that has already been signaled
CallStack (from HasCallStack):
  errorIO, called at src/Control/Concurrent/Extra.hs:196:16 in extra-1.7.9-B289Y5Rzkww81ONKh8ABWZ:Control.Concurrent.Extra
  signalBarrier, called at src/Development/IDE/LSP/LanguageServer.hs:64:16 in ghcide-1.1.0.0-inplace:Development.IDE.LSP.LanguageServer

Full test log:

  formats a range with CRLF endings:    Starting LSP server...
If you are seeing this in a terminal, you probably should have run ghcide WITHOUT the --lsp option!
Started LSP server in 0.00s
setInitialDynFlags cradle: Cradle {cradleRootDir = "/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata", cradleOptsProg = CradleAction: Default}
[Info] Registering ide configuration: IdeConfiguration {workspaceFolders = fromList [NormalizedUri (-6923107000992859315) "file:///home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata"], clientSettings = hashed Nothing}
[Debug] Set files of interest to: [(NormalizedFilePath "/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.hs",Modified {firstOpen = True})]
[Debug] Finishing build session(exception: AsyncCancelled)
[Debug] Restarting build session (aborting the previous one took 0.00s)
[Debug] Opened text document: file:///home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.hs
[Info] Consulting the cradle for "BrittanyCRLF.hs"
[Warning] No [cradle](https://github.com/mpickering/hie-bios#hie-bios) found for BrittanyCRLF.hs.
 Proceeding with [implicit cradle](https://hackage.haskell.org/package/implicit-hie).
You should ignore this message, unless you see a 'Multi Cradle: No prefixes matched' error.
Output from setting up the cradle Cradle {cradleRootDir = "/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata", cradleOptsProg = CradleAction: Default}
[Debug] Session loading result: Right (ComponentOptions {componentOptions = ["-dynamic"], componentRoot = "/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata", componentDependencies = []},"/usr/lib/ghc-8.10.4")
[Info] Using interface files cache dir: /home/berberman/.cache/ghcide/main-1a596a151463f2c53ee4feb14ecd276a1ccebfda
[Info] Making new HscEnv[main]
[Debug] New Component Cache HscEnvEq: (([],Just HscEnvEq 87),fromList [])
[Debug] Known files updated: fromList [(TargetFile NormalizedFilePath "/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.hs",fromList ["/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.hs"])]
[Debug] Restarting build session (aborting the previous one took 0.00s)
[Debug] Finishing build session(exception: AsyncCancelled)
[Info] finish: brittany (took 0.00s)
[Error] Fatal error in server thread: thread blocked indefinitely in an MVar operation
tests: Control.Concurrent.Extra.signalBarrier, attempt to signal a barrier that has already been signaled
CallStack (from HasCallStack):
  errorIO, called at src/Control/Concurrent/Extra.hs:196:16 in extra-1.7.9-B289Y5Rzkww81ONKh8ABWZ:Control.Concurrent.Extra
  signalBarrier, called at src/Development/IDE/LSP/LanguageServer.hs:64:16 in ghcide-1.1.0.0-inplace:Development.IDE.LSP.LanguageServer
[Debug] finish: InitialLoad (took 0.10s)
[Debug] Set files of interest to: [(NormalizedFilePath "/home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.hs",Modified {firstOpen = False})]
[Debug] Finishing build session(exception: AsyncCancelled)
[Debug] Restarting build session (aborting the previous one took 0.00s)
[Debug] Modified text document: file:///home/berberman/Desktop/haskell/haskell-language-server/plugins/hls-brittany-plugin/test/testdata/BrittanyCRLF.hs
[Debug] Finishing build session(exception: AsyncCancelled)
OK (0.45s)

pepeiborra · 2021-04-04T08:34:08Z

I thought you replaced this barrier with an MVar at some point - that change makes sense to me, since we call it from two places and therefore it shouldn't be a barrier.

The "thread blocked indefinitely in an MVar operation" error is ugly - it means that the main loop has finished and no longer holds a reference to the shared state, but there are background threads still waiting on MVars. It would be good to identify which threads and clean them up properly, or just make sure we use withAsync instead of async where possible

isovector · 2021-04-05T16:55:32Z

plugins/hls-tactics-plugin/hls-tactics-plugin.cabal

@@ -107,22 +107,6 @@ library
    TypeOperators,
    ViewPatterns

-
-executable test-server


This is an excellent change. Thanks!

jneira

Great work, thanks!

berberman · 2021-04-06T01:47:42Z

Branch protection feels unhappy with the skipped nix jobs :(

jneira · 2021-04-06T05:28:35Z

Branch protection feels unhappy with the skipped nix jobs :(

Umm, i have to change it to skip steps instead the entire job, like #1656

anka-213 · 2021-09-16T09:05:51Z

hls-test-utils/src/Test/Hls.hs

+silenceStderr :: IO a -> IO a
+silenceStderr action = withTempFile $ \temp ->
+  bracket (openFile temp ReadWriteMode) hClose $ \h -> do
+    old <- hDuplicate stderr
+    buf <- hGetBuffering stderr
+    h `hDuplicateTo'` stderr
+    action `finally` do
+      old `hDuplicateTo'` stderr
+      hSetBuffering stderr buf
+      hClose old


Does this mean that we can no longer use LSP_TEST_LOG_STDERR=1 to get more info about a failing test, since silencing stderr is now hard coded?

//cc @berberman

When I attempted this for all the ghcide testsuite, I installed a logger that sends output to the LSP channel.

https://github.com/haskell/haskell-language-server/pull/1752/files?file-filters%5B%5D=.hs&file-filters%5B%5D=.project#diff-46837fe41900682e7ad33f73eee0194cde2e864e3aebd7775d412660b61029fcR1

We could probably check for the environment variable manually and pretend that it was lsp-test that did it, to minimize disturbance of people's workflows.

(Here's lsp-test's code for it: https://github.com/haskell/lsp/blob/e707cbf5ca7077f70884ae0d2a8d016aa30ced5a/lsp-test/src/Language/LSP/Test.hs#L267-L275)

That way the current uses, like in ci doesn't have to change. Regardless of what we do, it should probably be documented together with the LSP_TEST_LOG_MESSAGES env variable in the contributing section, which it is currently not.

agree, pr's welcome!

Does this mean that we can no longer use LSP_TEST_LOG_STDERR=1 to get more info about a failing test, since silencing stderr is now hard coded?

Yes, output from lsp server is completely removed in test suites which use this function since that change, because there were too many logs were printed not through the logger, but were directly written to stderr, messing up testing status. So setting environment variable LSP_TEST_LOG_MESSAGES actually won't work. However, this function is a temporary workaround, and we should cleanup such code in server.

berberman requested a review from pepeiborra March 28, 2021 10:18

berberman commented Mar 28, 2021

View reviewed changes

hls-test-utils/src/Test/Hls.hs Outdated Show resolved Hide resolved

berberman force-pushed the plugin-tests2 branch 2 times, most recently from d29c7dd to 405635c Compare March 29, 2021 12:22

berberman marked this pull request as ready for review March 30, 2021 04:41

jneira added the type: testing label Mar 30, 2021

jneira self-requested a review March 30, 2021 05:33

pepeiborra reviewed Mar 31, 2021

View reviewed changes

hls-test-utils/src/Test/Hls.hs Show resolved Hide resolved

berberman commented Apr 2, 2021

View reviewed changes

hls-test-utils/src/Test/Hls.hs Show resolved Hide resolved

pepeiborra mentioned this pull request Apr 2, 2021

Shut the Shake session on exit, instead of restarting it #1655

Merged

berberman added 8 commits April 4, 2021 11:11

Sleep 0.5s after running a session

478fa77

Update CI

88d340a

Don't use withAsync

c711388

Add timeout

b40d923

Cancel the server action when timeout

e1e57d0

Fix cwd

e2d93ef

Close input stream manually, add a lock

ecc89c0

cleanup

ee3df16

berberman force-pushed the plugin-tests2 branch from 49ded9a to ee3df16 Compare April 4, 2021 03:14

tactics plugin

47c936d

pepeiborra approved these changes Apr 4, 2021

View reviewed changes

hls-test-utils/src/Test/Hls.hs Outdated Show resolved Hide resolved

berberman added 2 commits April 4, 2021 15:36

Remove sleep

b354ac4

Merge branch 'master' of github.com:haskell/haskell-language-server i…

dcf22de

…nto plugin-tests2

berberman mentioned this pull request Apr 4, 2021

Replace Barrier with MVar in lsp main #1668

Merged

Merge branch 'master' into plugin-tests2

8119d1a

berberman added the merge me Label to trigger pull request merge label Apr 5, 2021

Merge branch 'master' into plugin-tests2

5e09950

berberman linked an issue Apr 5, 2021 that may be closed by this pull request

CI jobs of plugins' test suites got stuck randomly #1627

Closed

isovector reviewed Apr 5, 2021

View reviewed changes

Merge branch 'master' into plugin-tests2

57e87e5

jneira approved these changes Apr 5, 2021

View reviewed changes

Merge branch 'master' into plugin-tests2

bd16a94

berberman merged commit 2d1a588 into haskell:master Apr 6, 2021

berberman deleted the plugin-tests2 branch April 6, 2021 07:37

berberman mentioned this pull request Apr 19, 2021

Retry tests on SQLError #1752

Closed

anka-213 reviewed Sep 16, 2021

View reviewed changes

	void $ waitAnyCancel =<< traverse async
	[ void $ LSP.runServerWithHandles
	inH
	outH
	serverDefinition
	, void $ waitBarrier clientMsgBarrier
	]

	-- These barriers are signaled when the threads reading from these chans exit.
	-- This should not happen but if it does, we will make sure that the whole server
	-- dies and can be restarted instead of losing threads silently.
	clientMsgBarrier <- newBarrier

	void $ waitAnyCancel =<< traverse async
	[ void $ LSP.runWithHandles
	stdin
	newStdout
	( const $ Right ()
	, handleInit (signalBarrier clientMsgBarrier ()) clientMsgChan
	)
	(handlers clientMsgChan)
	options
	Nothing
	, void $ waitBarrier clientMsgBarrier
	]
	where
	handleInit :: IO () -> TChan LSP.FromClientMessage -> LSP.LspFuncs () -> IO (Maybe LSP.ResponseError)
	handleInit exitClientMsg clientMsgChan lspFuncs@LSP.LspFuncs{..} = do
	Handlers{..} <- getHandlers lspFuncs
	let requestHandler' (req, reqId) = requestHandler
	(\res -> ResponseMessage "2.0" (responseId reqId) (Just res) Nothing)
	(\err -> ResponseMessage "2.0" (responseId reqId) Nothing (Just $ ResponseError err "" Nothing))
	req
	_ <- flip forkFinally (const exitClientMsg) $ forever $ do
	msg <- atomically $ readTChan clientMsgChan
	case convClientMsg msg of
	Nothing -> Logger.logSeriousError loggerH $ "Unknown client msg: " <> T.pack (show msg)
	Just (Left notif) -> notificationHandler notif
	Just (Right req) -> sendFunc =<< requestHandler' req
	pure Nothing

	let cleanup
	\| Just sp <- mServerProc = do
	-- Give the server some time to exit cleanly
	-- It makes the server hangs in windows so we have to avoid it
	#ifndef mingw32_HOST_OS
	timeout msgTimeoutMs (waitForProcess sp)
	#endif
	cleanupProcess (Just serverIn, Just serverOut, Nothing, sp)
	\| otherwise = pure ()
	finally (timeout msgTimeoutMs (runSession' exitServer))
	-- Make sure to kill the listener first, before closing
	-- handles etc via cleanupProcess
	(killThread tid >> cleanup)

Run plugins' test suites with server in the same process #1628

Run plugins' test suites with server in the same process #1628

Conversation

berberman commented Mar 27, 2021

berberman commented Mar 28, 2021

pepeiborra commented Mar 28, 2021

berberman commented Mar 29, 2021 • edited Loading

berberman commented Mar 30, 2021

jneira commented Mar 30, 2021

jneira commented Mar 31, 2021

berberman commented Mar 31, 2021

pepeiborra commented Mar 31, 2021

jneira commented Mar 31, 2021

berberman commented Apr 1, 2021

pepeiborra commented Apr 1, 2021

pepeiborra commented Apr 1, 2021

berberman commented Apr 1, 2021

berberman commented Apr 1, 2021 • edited Loading

wz1000 commented Apr 1, 2021

Choose a reason for hiding this comment

pepeiborra Apr 2, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

berberman Apr 2, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

berberman commented Apr 2, 2021

pepeiborra commented Apr 2, 2021 • edited Loading

berberman commented Apr 3, 2021

pepeiborra commented Apr 3, 2021

berberman commented Apr 4, 2021

pepeiborra commented Apr 4, 2021

Choose a reason for hiding this comment

jneira left a comment

Choose a reason for hiding this comment

berberman commented Apr 6, 2021

jneira commented Apr 6, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

berberman commented Mar 29, 2021 •

edited

Loading

berberman commented Apr 1, 2021 •

edited

Loading

pepeiborra Apr 2, 2021 •

edited

Loading

berberman Apr 2, 2021 •

edited

Loading

pepeiborra commented Apr 2, 2021 •

edited

Loading