More flaky tests (mainly in windows)

[jneira]

• https://github.com/haskell/haskell-language-server/runs/3500143128?check_suite_focus=true

   cradle
    loading
      load cradle only once
        implicit:                                                                                         OK (1.07s)
        direct:                                                                                           OK (0.78s)
      retry failed:                                                                                       FAIL (0.59s)
        test\exe\Main.hs:4928:
        No joy after fixing the cradle
        Use -p '/retry failed/' to rerun this test only.

• for windows and ghc-8.10.2.2 (i am gonna disable this one soon)

[ 7 of 61] Compiling Development.IDE.Session.VersionCheck ( session-loader\Development\IDE\Session\VersionCheck.hs, D:\a\haskell-language-server\haskell-language-server\dist-newstyle\build\x86_64-windows\ghc-8.10.2\ghcide-1.4.1.0\build\Development\IDE\Session\VersionCheck.o )

Access violation in generated code when reading 0x31d0

 Attempting to reconstruct a stack trace...

   Frame	Code address
 * 0x48fda90	0x399be6d C:\ProgramData\chocolatey\lib\ghc.8.10.2.2\tools\ghc-8.10.2\bin\ghc.exe+0x359be6d
 * 0x48fda98	0x33c92ca C:\ProgramData\chocolatey\lib\ghc.8.10.2.2\tools\ghc-8.10.2\bin\ghc.exe+0x2fc92ca
 * 0x48fdaa0	0x16
 * 0x48fdaa8	0x8a507f9
 * 0x48fdab0	0x7ff81edfb7e0 C:\Windows\System32\KERNEL32.DLL+0x1b7e0
 * 0x48fdab8	0x90c

• for windows and ghc-9.0.1 (https://github.com/haskell/haskell-language-server/runs/3500529485?check_suite_focus=true)

C:\Users\RUNNER~1\AppData\Local\Temp\ghcAD66.o.tmp: renameFile:renamePath:MoveFileEx "\\\\?\\C:\\Users\\RUNNER~1\\AppData\\Local\\Temp\\ghcAD66.o.tmp" Just "\\\\?\\C:\\Users\\RUNNER~1\\AppData\\Local\\Temp\\ghcAD66.o": does not exist (The system cannot find the file specified.)
Preprocessing library for hls-graph-1.4.0.0..
Building library for hls-graph-1.4.0.0..
cabal.exe: Failed to build hie-compat-0.2.1.0 (which is required by test:tests
from hls-eval-plugin-1.1.2.0). The failure occurred during the configure step.

• Flaky GHCIDE test: Timestamps do not have millisecond (ignored for now) #2115
• session-deps-are-picked-up: Timed out waiting to receive a message from the server. (More flaky tests (mainly in windows) #2153 (comment)) fixed by Stabilize the build system by correctly house keeping the dirtykeys and rule values [flaky test #4185 #4093] #4190
• The nasty and generic Timed out waiting to receive a message from the server. More flaky tests (mainly in windows) #2153 (comment)
• Another good old friend: Exception: fd:111: hPutBuf: resource vanished (Broken pipe) Tests randomly fail with "Exception: fd:111: hPutBuf: resource vanished (Broken pipe)" (--test-option=-j1 workaround) #1875
• windows + ghc-9.0.1 build error renameFile:renamePath:MoveFileEx file : does not exist (The system cannot find the file specified.)
• The test "lower-case drive" fails randomly in Windows:

[jneira]

* for windows and ghc-8.10.2.2 (i am gonna disable this one soon)

disabled with #2154

[jneira]

https://github.com/haskell/haskell-language-server/runs/3505220254?check_suite_focus=true

  cradle
    dependencies
      session-deps-are-picked-up:                                                                         FAIL
        Exception: Timed out waiting to receive a message from the server.
        Last message received:
        {
            "method": "$/progress",
            "params": {
                "value": {
                    "kind": "end"
                },
                "token": "14"
            },
            "jsonrpc": "2.0"
        }
        Use -p '/session-deps-are-picked-up/' to rerun this test only.

[jneira]

Lets see if the amazing work fixing flaky tests in #2243 fix some of those ones

[jneira]

This one is in ubuntu and hls-eva-plugin:

 FAIL (1.16s)
    Test output was different from 'test/testdata/THaddock.expected.hs'. Output of ["git","-c","core.fileMode=false","diff","--no-index","--text","--exit-code","test/testdata/THaddock.expected.hs","/tmp/THaddock.expected82807-25.actual"]:
    diff --git a/test/testdata/THaddock.expected.hs b/tmp/THaddock.expected82807-25.actual
    index 222bedf..b879e41 100644
    --- a/test/testdata/THaddock.expected.hs
    +++ b/tmp/THaddock.expected82807-25.actual
    @@ -22,7 +22,17 @@ double :: Num a => a -> a
     double a = a + a
     -- ^ Single line backward comments
     -- >>> double 11
    --- 22
    +-- <BLANKLINE>
    +-- GHC.ByteCode.Linker.lookupCE
    +-- During interactive linking, GHCi couldn't find the following symbol:
    +--   interactive_Ghci1_evalPrint_closure
    +-- This may be due to you not asking GHCi to load extra object files,
    +-- archives or DLLs needed by your current session.  Restart GHCi, specifying
    +-- the missing library using the -L/path/to/object/dir and -lmissinglibname
    +-- flags, or simply by naming the relevant files on the GHCi command line.
    +-- Alternatively, this link failure might indicate a bug in GHCi.
    +-- If you suspect the latter, please report this as a GHC bug:
    +--   https://www.haskell.org/ghc/reportabug
     
     twice :: [a] -> [a]
     twice a <truncated>
    Use --accept or increase --size-cutoff to see full output.
    Use -p '/Evaluate expressions in Haddock comments in both single line and multi line format/' to rerun this test only.

[jneira]

• A frequent build error in windows + ghc-9.0.1:

 Failed to build lsp-1.2.0.1. The failure occurred during the configure step.
Build log (
C:\Users\runneradmin\AppData\Roaming\cabal\logs\ghc-9.0.1\lsp-1.2.0.1-381c3d12187ac032fd2f3e5c5e55a4b28ee306b6.log
cabal.exe: Failed to build lsp-1.2.0.1 (which is required by test:wrapper-test
):
from hls-1.4.0.0 and test:func-test from hls-1.4.0.0). See the build log above
Configuring library for lsp-1.2.0.1..
for details.
C:\Users\RUNNER~1\AppData\Local\Temp\ghcAAE5.o.tmp: renameFile:renamePath:MoveFileEx "\\\\?\\C:\\Users\\RUNNER~1\\AppData\\Local\\Temp\\ghcAAE5.o.tmp" Just "\\\\?\\C:\\Users\\RUNNER~1\\AppData\\Local\\Temp\\ghcAAE5.o": does not exist (The system cannot find the file specified.)

[jneira]

From #2381

• The test "lower-case drive" fails randomly in Windows

ghcide
  diagnostics
    lower-case drive: FAIL (2.55s)
      test\exe\Main.hs:551:
      Got unexpected diagnostics for Uri {getUri = "file:///C:/Users/runneradmin/AppData/Local/Temp/extra-dir-816443890125/A/A.hs"} got List [Diagnostic {_range = Range {_start = Position {_line = 0, _character = 0}, _end = Position {_line = 1, _character = 0}}, _severity = Just DsError, _code = Nothing, _source = Just "compiler", _message = "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\extra-dir-816443890125\\A\\A.hs: getModificationTime:CreateFile \"\\\\\\\\?\\\\C:\\\\Users\\\\runneradmin\\\\AppData\\\\Local\\\\Temp\\\\extra-dir-816443890125\\\\A\\\\A.hs\": does not exist (The system cannot find the file specified.)", _tags = Nothing, _relatedInformation = Nothing}]

[eddiemundo]

Summary of the "lower-case drive" test on windows ghc 9.0.1 from reading test and logs:

• Test writes contentsB to A/B.hs the filesystem.
• Test sends notification to server that A/A.hs was opened containing contentsA. It does not write A/A.hs to the filesystem.
• A/A.hs is added to files of interest.
• Implicit cradle for A/A.hs is used
• Build session finished (exception: AsyncCancelled)
• Restarting build session due to A/A.hs modified for keys [GetModificationTime; A/A.hs, IsFileOfIntereset; A/A.hs]
• Cradle is loaded
• Session loading result: Right (ComponentOptions {componentOptions = [], componentRoot = "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\extra-dir-969597073458", componentDependencies = []},"C:\\tools\\ghc-9.0.1\\lib")
• New Component Cache HscEnvEq: (([],Just HscEnvEq 7),fromList [])
• GetKnownTargets now has A/A.hs -> A/A.hs
• Finishing build session (exception: AsyncCancelled)
• Restarting build because new component for keys [GetKnownTargets; ,GetModificationTime; A\A.hs, GhcSessionIO; ,IsFileOfInterest; \A\A.hs]
• Implicit cradle for A/B.hs
• Session loading result: Right (ComponentOptions {componentOptions = [], componentRoot = "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\extra-dir-969597073458", componentDependencies = []},"C:\\tools\\ghc-9.0.1\\lib")
• New Component Cache HscEnvEq: (([],Just HscEnvEq 11),fromList [])
• New Component Cache HscEnvEq: (([],Just HscEnvEq 12),fromList [])
• Restarting build session due to new component for keys [GetKnownTargets; ,GhcSessionIO; ]
• We get the diagnostic we expect
• Client sends textDocument/didClose A/A.hs
• Remove A/A.hs from files of interest (it is now fromList [])
• Finishing build session (exception: AsyncCancelled)
• Restart build due to Closed text document A/A.hs for keys [IsFileOfInterest; A/A.hs, GetModificationTime; A/B.hi]
• dirty GC of 5 keys
• ghcide/GC [NeedsCompilation; A/A.hs, ...]
• textDocument/publishDiagnostics, A/A.hs does not exist (The system cannot find the file specified.)

So in the end we want to recompile A/A.hs but it doesn't actually exist on disk. Don't know why this happens only on windows, and why it only sometimes happens, but I guess the difference is ghcide/GC happening non-deterministically.

Maybe writing contentsA to A/A.hs in the filesystem in the test would solve this problem, but I don't know if that's necessary or right.

[pepeiborra]

Thanks for the analysis!

After closing A.hs the set of files of interest is [], therefore the next build should not be doing much.

But there can be still targets in the build queue from a previous build, which require A.hs. In that case, the GC is happening prematurely and should be delayed until the build queue is empty. I'll add some logging to confirm.

[pepeiborra]

I just found that the "lower-case drive" test can fail with 0 keys GC'ed, which suggests that the problem is not GC related.

Instead, I think the problem might be the "InitialLoad" build target that type checks all the project files at startup. The event sequence is as follows:

1. A.hs is opened and added to the KnownTargets set
2. A new component is created for A.hs and an "InitialLoad" build is fired
3. A.hs is type checked as part of the "InitialLoad"
4. A.hs is closed

The ordering of 3 and 4 is non deterministic. If 4 happens before 3, then the test will crash since A.hs does not exist on disk.

We should probably disable this option (checkStartup) in the whole testsuite

[jneira]

hope other tests don't rely in the initial load to work...
could not we make 3 and 4 deterministic?, close the file should not interrupt whatever the server is doing with the file?

[pepeiborra]

If there are tests that rely on the initial load, we should stop them from doing so.

Do you have any suggestions on how to make 3 and 4 deterministic? I don't see how.

[jneira]

Do you have any suggestions on how to make 3 and 4 deterministic? I don't see how.

Are we not already cancelling processing using async exceptions? could we not cancell the typechecking when a close file event is send by the client or a file watcher? Or the client close effectively the file without waiting to any clean up in the server?

sorry if i am missing something obvious

[pepeiborra]

Do you have any suggestions on how to make 3 and 4 deterministic? I don't see how.

Are we not already cancelling processing using async exceptions? could we not cancell the typechecking when a close file event is send by the client or a file watcher? Or the client close effectively the file without waiting to any clean up in the server?

sorry if i am missing something obvious

It's a bit more subtle than that. Action computations are cancelled when the build is restarted yes, but then they are re-enqueued to run on the next build. This is by design and it means that there is no simple way to cancel the initial load. It would not be possible to filter the build queue when a file gets closed because the actions in the queue are not indexed by a NormalizedFilePath.

In any case the contract for checkProject is to check all the files on startup, regardless of whether a file is open or closed in the editor. So I'm not convinced that cancellation is the right approach here.

[jneira]

We have to analyze current behaviour, it seems tests are not so flaky nowadays

[jneira]

closing as those flaky tests are not present or they are not throwed repeteadly

[soulomoon]

Still seeing them