Wingman: TODO(sandy) error pops up after the first tactic #2448

lsmor · 2021-12-07T11:09:55Z

Your environment

Which OS do you use:
Ubuntu 20.04.3 LTS

Which lsp-client do you use:
VS Code

Describe your project (alternative: link to the project):
It is a regular stack project which can be found here. Nothing really wierd, just a normal advent of code project with one executable per day.

stack snapshot: 18.6 -> GHC 8.10.7
HLS version: 1.5.1

Steps to reproduce

write the following file and positionate the cursor on the underscore, then trigger the code action "Wingman: case split on d"

module Main where

data Input = Input

example :: Input -> Input
example d = _


main :: IO ()
main = print "hello hls"

Expected behaviour

It should complete the line example d = _ introducing Input constructor like example Input = _d. Some times, It works fine when I re-start hls but 8 out of 10 times it keeps failing.

Actual behaviour

And error pops up TODO(sandy)

Include debug information

This is the output when I set VS code extension setting to debug. (I've been unable to run haskell-language-server-wrapper)

Debug output:

2021-12-07 12:01:51.274203053 [ThreadId 4442] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)
2021-12-07 12:01:51.274730682 [ThreadId 4443] INFO hls:	finish: Wingman.judgementForHole.GetHieAst (took 0.00s)
2021-12-07 12:01:51.275544442 [ThreadId 4444] INFO hls:	finish: Wingman.judgementForHole.GetBindings (took 0.00s)
2021-12-07 12:01:51.275816949 [ThreadId 4445] INFO hls:	finish: Wingman.judgementForHole.TypeCheck (took 0.00s)
[Error - 12:01:51] Request workspace/executeCommand failed.
  Message: TODO(sandy)
  Code: -32603 
2021-12-07 12:01:51.276098968 [ThreadId 4446] INFO hls:	finish: Wingman.judgementForHole.GhcSessionDeps (took 0.00s)
2021-12-07 12:01:51.350012789 [ThreadId 4464] INFO hls:	finish: Pragmas.GetParsedModule (took 0.00s)
2021-12-07 12:01:51.350191098 [ThreadId 4467] INFO hls:	finish: retrie (took 0.00s)
2021-12-07 12:01:51.350225369 [ThreadId 4465] INFO hls:	finish: Wingman.getIdeDynflags.GetModSummaryWithoutTimestamps (took 0.00s)

The text was updated successfully, but these errors were encountered:

jneira · 2021-12-07T11:38:55Z

thanks for the bug report, pinging @isovector due to the explicit mention 😉

wenkokke · 2021-12-09T11:30:28Z

I'm having the same issue with VSCode on macOS (11.6) with HLS 1.5.1.

isovector · 2021-12-09T16:28:08Z

Which version of GHC, @wenkokke ? I'll see if I can repro this on the weekend.

wenkokke · 2021-12-10T10:39:43Z

I got these errors with GHC 8.10.7, using any of the case splitting primitives except for introduce-and-destruct, so my experience is consistent with the errors shown above.

I can do a bit more thorough testing if that’d help?

isovector · 2021-12-10T16:15:22Z

That would be extremely helpful, thanks. The block that pushes out the error message is a MaybeT over mostly HLS functionality. I haven't touched Wingman for a few releases, so my guess is that something in the infrastructure has changed --- likely one of the data sources that used to be blocking is no longer.

Do you notice more successes if you wait for 30 seconds after making the last change? Do you see this problem less often on smaller projects?

wenkokke · 2021-12-10T19:40:51Z

Do you notice more successes if you wait for 30 seconds after making the last change? Do you see this problem less often on smaller projects?

I see this error on every single attempt that I make to pattern match regardless of project size (though I have only tested it on small projects).

I'm guessing that the amount of time that I wait doesn't really affect things, and I think that I haven't been calling these functions immediately... but I'm not sure. I will report back.

wenkokke · 2021-12-10T19:46:07Z

I started a cabal project with only a single file with only the following lines:

module Test where

nope :: Bool -> Bool
nope b = _wc

Now running "Case split on b" raises "TODO(sandy)" as a popup. However, "introduce lambda" works just fine, e.g., to obtain the above code from:

nope :: Bool -> Bool
nope = _

Similarly, "introduce and destruct term" works just fine.

The amount of time waited has no effect on any of these behaviors.

isovector · 2021-12-10T20:57:24Z

My guess is that something broke the datacon lookup stuff. The most recent change to this function was #2128. I'm traveling right now, but will try to find some time to dig in over the weekend.

lsmor · 2021-12-12T10:41:11Z

Hi @isovector . I've tried different approaches and found that Wingman is able to perfom one action, but not two. the error is not so related with the action but with number of actions you want to perform. Let me explain via example.

1 . Start with this file.

data Dummy a = Dummy a

f :: Dummy Int -> Int
f = _

2. If I launch "Introduce lambda", It doesn't fail

data Dummy a = Dummy a

f :: Dummy Int -> Int
f du = _wa

3. If after (2) I launch "case split on du" It fails with TODO(sandy).

data Dummy a = Dummy a

f :: Dummy Int -> Int
f du = _wa -- Fails when triying "case split" action

3.1 If now, I come back to (1) and hit again "Introduce lambda" it fails with the same error

data Dummy a = Dummy a

f :: Dummy Int -> Int
f = _  -- Now this fails after first fail at (2)

3.2 If after (3) I re-start `HLS` and rehit "case split on du"... It does work fine!!

data Dummy a = Dummy a

f :: Dummy Int -> Int
f (Dummy n) = _wa   -- now it is working

4. If "attempt to fill hole" is launched it fails with same error.

data Dummy a = Dummy a

f :: Dummy Int -> Int
f (Dummy n) = _wa   -- Fails after attempt to fill hole.

4.1 If at (4) I restart `HLS` andt rehit "attempt to fill hole" now it works fine.

data Dummy a = Dummy a

f :: Dummy Int -> Int
f (Dummy n) = n   -- it works.

FYI: @wenkokke

wenkokke · 2021-12-12T12:09:12Z

I can confirm that this is indeed the case!

isovector · 2021-12-12T21:23:17Z

Thanks for the repro! It sounds like something is going wrong in the HLS dependency cache. I'll take a look ASAP.

isovector · 2021-12-12T22:25:06Z

OK, I can repro as well. Looking into it now.

isovector · 2021-12-12T22:39:45Z

So interestingly, we can run different commands if we undo the change wingman just made. EG split > undo > auto works just fine. Sounds a lot like the HLS cache isn't getting updated.

isovector · 2021-12-12T22:56:21Z

This is the line that's failing:

haskell-language-server/plugins/hls-tactics-plugin/src/Wingman/LanguageServer.hs

Line 316 in 0b6b5ec

    
           case selectSmallestContaining (rangeToRealSrcSpan (FastString.unpackFS fs) range) ast of

isovector · 2021-12-12T23:17:22Z

Here is the dumped ast:

(Node
 (NodeInfo
  (fromList
   [((,)
     {FastString: "Module"}
     {FastString: "Module"})])
  []
  (fromList
   []))
 ({abstract:RealSrcSpan})
 [(Node
   (NodeInfo
    (fromList
     [((,)
       {FastString: "DataDecl"}
       {FastString: "TyClDecl"})])
    []
    (fromList
     []))
   ({abstract:RealSrcSpan})
   [(Node
     (NodeInfo
      (fromList
       [])
      []
      (fromList
       [((,)
         (Right
          {Name: Dummy})
         (IdentifierDetails
          (Nothing)
          (fromList
           [(Decl
             (DataDec)
             (Just
              ({abstract:RealSrcSpan})))])))]))
     ({abstract:RealSrcSpan})
     [])
   ,(Node
     (NodeInfo
      (fromList
       [((,)
         {FastString: "UserTyVar"}
         {FastString: "HsTyVarBndr"})])
      []
      (fromList
       [((,)
         (Right
          {Name: a})
         (IdentifierDetails
          (Nothing)
          (fromList
           [(TyVarBind
             (NoScope)
             (ResolvedScopes
              [(NoScope)
              ,(LocalScope
                ({abstract:RealSrcSpan}))]))])))]))
     ({abstract:RealSrcSpan})
     [])
   ,(Node
     (NodeInfo
      (fromList
       [((,)
         {FastString: "ConDeclH98"}
         {FastString: "ConDecl"})])
      []
      (fromList
       []))
     ({abstract:RealSrcSpan})
     [(Node
       (NodeInfo
        (fromList
         [])
        []
        (fromList
         [((,)
           (Right
            {Name: Dummy})
           (IdentifierDetails
            (Nothing)
            (fromList
             [(Decl
               (ConDec)
               (Just
                ({abstract:RealSrcSpan})))])))]))
       ({abstract:RealSrcSpan})
       [])
     ,(Node
       (NodeInfo
        (fromList
         [((,)
           {FastString: "HsTyVar"}
           {FastString: "HsType"})])
        []
        (fromList
         [((,)
           (Right
            {Name: a})
           (IdentifierDetails
            (Nothing)
            (fromList
             [(Use)])))]))
       ({abstract:RealSrcSpan})
       [])])])
 ,(Node
   (NodeInfo
    (fromList
     [((,)
       {FastString: "TypeSig"}
       {FastString: "Sig"})])
    []
    (fromList
     []))
   ({abstract:RealSrcSpan})
   [(Node
     (NodeInfo
      (fromList
       [])
      []
      (fromList
       [((,)
         (Right
          {Name: f})
         (IdentifierDetails
          (Nothing)
          (fromList
           [(TyDecl)])))]))
     ({abstract:RealSrcSpan})
     [])
   ,(Node
     (NodeInfo
      (fromList
       [((,)
         {FastString: "HsFunTy"}
         {FastString: "HsType"})])
      []
      (fromList
       []))
     ({abstract:RealSrcSpan})
     [(Node
       (NodeInfo
        (fromList
         [((,)
           {FastString: "HsAppTy"}
           {FastString: "HsType"})])
        []
        (fromList
         []))
       ({abstract:RealSrcSpan})
       [(Node
         (NodeInfo
          (fromList
           [((,)
             {FastString: "HsTyVar"}
             {FastString: "HsType"})])
          []
          (fromList
           [((,)
             (Right
              {Name: Dummy})
             (IdentifierDetails
              (Nothing)
              (fromList
               [(Use)])))]))
         ({abstract:RealSrcSpan})
         [])
       ,(Node
         (NodeInfo
          (fromList
           [((,)
             {FastString: "HsTyVar"}
             {FastString: "HsType"})])
          []
          (fromList
           [((,)
             (Right
              {Name: Int})
             (IdentifierDetails
              (Nothing)
              (fromList
               [(Use)])))]))
         ({abstract:RealSrcSpan})
         [])])
     ,(Node
       (NodeInfo
        (fromList
         [((,)
           {FastString: "HsTyVar"}
           {FastString: "HsType"})])
        []
        (fromList
         [((,)
           (Right
            {Name: Int})
           (IdentifierDetails
            (Nothing)
            (fromList
             [(Use)])))]))
       ({abstract:RealSrcSpan})
       [])])])
 ,(Node
   (NodeInfo
    (fromList
     [((,)
       {FastString: "AbsBinds"}
       {FastString: "HsBindLR"})
     ,((,)
       {FastString: "FunBind"}
       {FastString: "HsBindLR"})
     ,((,)
       {FastString: "Match"}
       {FastString: "Match"})])
    [(FunTy
      (VisArg)
      (TyConApp
       ({abstract:TyCon})
       [(TyConApp
         ({abstract:TyCon})
         [])])
      (TyConApp
       ({abstract:TyCon})
       []))]
    (fromList
     []))
   ({abstract:RealSrcSpan})
   [(Node
     (NodeInfo
      (fromList
       [])
      []
      (fromList
       [((,)
         (Right
          {Name: f})
         (IdentifierDetails
          (Just
           (FunTy
            (VisArg)
            (TyConApp
             ({abstract:TyCon})
             [(TyConApp
               ({abstract:TyCon})
               [])])
            (TyConApp
             ({abstract:TyCon})
             [])))
          (fromList
           [(MatchBind)
           ,(ValBind
             (RegularBind)
             (ModuleScope)
             (Just
              ({abstract:RealSrcSpan})))])))]))
     ({abstract:RealSrcSpan})
     [])
   ,(Node
     (NodeInfo
      (fromList
       [((,)
         {FastString: "VarPat"}
         {FastString: "Pat"})])
      [(TyConApp
        ({abstract:TyCon})
        [(TyConApp
          ({abstract:TyCon})
          [])])]
      (fromList
       [((,)
         (Right
          {Name: n})
         (IdentifierDetails
          (Just
           (TyConApp
            ({abstract:TyCon})
            [(TyConApp
              ({abstract:TyCon})
              [])]))
          (fromList
           [(PatternBind
             (LocalScope
              ({abstract:RealSrcSpan}))
             (NoScope)
             (Nothing))])))]))
     ({abstract:RealSrcSpan})
     [])
   ,(Node
     (NodeInfo
      (fromList
       [((,)
         {FastString: "GRHS"}
         {FastString: "GRHS"})])
      []
      (fromList
       []))
     ({abstract:RealSrcSpan})
     [(Node
       (NodeInfo
        (fromList
         [((,)
           {FastString: "HsUnboundVar"}
           {FastString: "HsExpr"})
         ,((,)
           {FastString: "HsVar"}
           {FastString: "HsExpr"})])
        [(TyConApp
          ({abstract:TyCon})
          [])]
        (fromList
         [((,)
           (Right
            {Name: __a6Qy})
           (IdentifierDetails
            (Just
             (TyConApp
              ({abstract:TyCon})
              []))
            (fromList
             [(Use)])))]))
       ({abstract:RealSrcSpan})
       [])])])])

not super helpful without the RSS --- though the one we're looking for is SrcSpanPoint "/home/sandy/prj/test/src/Lib.hs" 6 18

isovector · 2021-12-12T23:34:17Z

Here's a trace of finding the right src span

!!!node span: SrcSpanMultiLine "/home/sandy/prj/test/src/Lib.hs" 3 1 6 8
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 3 1 23
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 5 1 22
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 1 8
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 1 2
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 3 4
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 5 8
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 7 8

and here's what happens when it fails:

!!!node span: SrcSpanMultiLine "/home/sandy/prj/test/src/Lib.hs" 3 1 6 8

isovector · 2021-12-12T23:42:32Z

Upon restarting, here's what we get for the previous failing case:

!!!OK?: SrcSpanPoint "/home/sandy/prj/test/src/Lib.hs" 6 18
!!!node span: SrcSpanMultiLine "/home/sandy/prj/test/src/Lib.hs" 3 1 6 18
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 3 1 23
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 5 1 22
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 1 18
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 1 2
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 3 12
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 13 18
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 15 18
!!!NICE: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 6 15 18

isovector · 2021-12-12T23:44:29Z

The asts we get come from here:

haskell-language-server/plugins/hls-tactics-plugin/src/Wingman/LanguageServer.hs

Line 214 in 0b6b5ec

TrackedStale asts amapping <- stale GetHieAst

which is explicitly marked as OK to be stale. That's probably the issue, and maybe the behavior here has changed.

isovector · 2021-12-12T23:50:58Z

That doesn't appear to fix the issue.

Weird: running the code action gives us this output:

!!!OK?: SrcSpanPoint "/home/sandy/prj/test/src/Lib.hs" 6 18
!!!node span: SrcSpanMultiLine "/home/sandy/prj/test/src/Lib.hs" 3 1 6 8
[Error - 3:50:07 PM] Request workspace/executeCommand failed.
  Message: TODO(sandy)
  Code: -32603

but immediately after, we get a hover update, and this output

!!!OK?: SrcSpanPoint "/home/sandy/prj/test/src/Lib.hs" 6 18
!!!node span: SrcSpanMultiLine "/home/sandy/prj/test/src/Lib.hs" 3 1 6 18
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 3 1 23
!!!node span: SrcSpanOneLine "/home/sandy/prj/test/src/Lib.hs" 5 1 22
...

so for some reason, hovers are looking at fresh data, but code actions are not.

... which explains why the code actions appear as possibilities in the first place.

isovector · 2021-12-12T23:52:38Z

Are code actions being cached? Like, they get generated once when the file is loaded, and then never again? @pepeiborra

pepeiborra · 2021-12-13T00:10:55Z

No, but we changed the way cache invalidation works for the build graph. Previously the build system would scan all the build nodes to find out what has changed, now it gets that information from the caller, i.e. ghcide. This is new in HLS 1.5.0 and requires using recordDirtyKeys explicitly on leaf build nodes, like GetModificationTime or GetFileContents.

Maybe you need to call recordDirtyKeys on the custom build rules that Wingman defines? It shouldn't be necessary if they have proper dependencies (the build system tracks reverse dependencies) but it's worth checking.

isovector · 2021-12-13T01:45:59Z

As far as I can tell, this is not a bug in Wingman. I'm going to run a bisect and see where it goes wrong.

isovector · 2021-12-13T04:04:58Z

Bisect says 682386d is to blame.

isovector · 2021-12-13T05:44:19Z

I'll get a proper test coded up tomorrow, and maybe @pepeiborra could help me spelunk through 682386d

pepeiborra · 2021-12-13T08:43:45Z

@isovector if I change the action in Wingman rules to mark WriteDiagnostics as dirty, the problem goes away:

  action $ do
    files <- getFilesOfInterestUntracked
    extras <- getShakeExtras
    liftIO $ join $ atomically $ recordDirtyKeys extras WriteDiagnostics (Map.keys files)
    void $ uses WriteDiagnostics $ Map.keys files

haskell-language-server/plugins/hls-tactics-plugin/src/Wingman/LanguageServer.hs

Lines 596 to 597 in ce1f353

    
           action $ do 
        
             files <- getFilesOfInterestUntracked

pepeiborra · 2021-12-13T08:44:57Z

I don't understand why this is necessary though, it could mean a bug in hls-graph

isovector · 2021-12-13T15:32:32Z

Thanks for investigating, Pepe. Greatly appreciated! I'll get that merged later today.

lsmor added status: needs triage type: bug Something isn't right: doesn't work as intended, documentation is missing/outdated, etc.. labels Dec 7, 2021

jneira added component: wingman and removed status: needs triage labels Dec 7, 2021

isovector self-assigned this Dec 10, 2021

isovector mentioned this issue Dec 13, 2021

Wingman: Fix subsequent tactics #2479

Closed

isovector changed the title ~~TODO(sandy) error pop up inconsistenly~~ Wingman: TODO(sandy) error pops up after the first tactic Dec 13, 2021

jneira added this to the 1.6.0 milestone Dec 15, 2021

isovector mentioned this issue Dec 15, 2021

WIP: GHC-9.0 support for hls-tactics-plugin #2202

Closed

isovector mentioned this issue Jan 12, 2022

Wingman: Fix TODO(sandy) when performing subsequent actions #2580

Merged

mergify bot closed this as completed in #2580 Jan 13, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Wingman: TODO(sandy) error pops up after the first tactic #2448

Wingman: TODO(sandy) error pops up after the first tactic #2448

lsmor commented Dec 7, 2021 •

edited

Loading

jneira commented Dec 7, 2021

wenkokke commented Dec 9, 2021

isovector commented Dec 9, 2021

wenkokke commented Dec 10, 2021 •

edited

Loading

isovector commented Dec 10, 2021

wenkokke commented Dec 10, 2021

wenkokke commented Dec 10, 2021 •

edited

Loading

isovector commented Dec 10, 2021

lsmor commented Dec 12, 2021

wenkokke commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021 •

edited

Loading

isovector commented Dec 12, 2021

pepeiborra commented Dec 13, 2021

isovector commented Dec 13, 2021

isovector commented Dec 13, 2021

isovector commented Dec 13, 2021

pepeiborra commented Dec 13, 2021

pepeiborra commented Dec 13, 2021

isovector commented Dec 13, 2021 •

edited

Loading

Wingman: TODO(sandy) error pops up after the first tactic #2448

Wingman: TODO(sandy) error pops up after the first tactic #2448

Comments

lsmor commented Dec 7, 2021 • edited Loading

Your environment

Steps to reproduce

Expected behaviour

Actual behaviour

Include debug information

jneira commented Dec 7, 2021

wenkokke commented Dec 9, 2021

isovector commented Dec 9, 2021

wenkokke commented Dec 10, 2021 • edited Loading

isovector commented Dec 10, 2021

wenkokke commented Dec 10, 2021

wenkokke commented Dec 10, 2021 • edited Loading

isovector commented Dec 10, 2021

lsmor commented Dec 12, 2021

1 . Start with this file.

2. If I launch "Introduce lambda", It doesn't fail

3. If after (2) I launch "case split on du" It fails with TODO(sandy).

3.1 If now, I come back to (1) and hit again "Introduce lambda" it fails with the same error

3.2 If after (3) I re-start HLS and rehit "case split on du"... It does work fine!!

4. If "attempt to fill hole" is launched it fails with same error.

4.1 If at (4) I restart HLS andt rehit "attempt to fill hole" now it works fine.

wenkokke commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021

isovector commented Dec 12, 2021 • edited Loading

isovector commented Dec 12, 2021

pepeiborra commented Dec 13, 2021

isovector commented Dec 13, 2021

isovector commented Dec 13, 2021

isovector commented Dec 13, 2021

pepeiborra commented Dec 13, 2021

pepeiborra commented Dec 13, 2021

isovector commented Dec 13, 2021 • edited Loading

lsmor commented Dec 7, 2021 •

edited

Loading

wenkokke commented Dec 10, 2021 •

edited

Loading

wenkokke commented Dec 10, 2021 •

edited

Loading

3.2 If after (3) I re-start `HLS` and rehit "case split on du"... It does work fine!!

4.1 If at (4) I restart `HLS` andt rehit "attempt to fill hole" now it works fine.

isovector commented Dec 12, 2021 •

edited

Loading

isovector commented Dec 13, 2021 •

edited

Loading