Stack build gives "cannot satisfy" errors after a while

[hesselink]

I'm sorry if this report is very vague, but I figured I'd report it anyway: when using stack 0.1.10 (but not 0.1.8), after a while we get "cannot satisfy" errors like this:

--  While building package silk-tag-document-0.3.0.1 using:
      /Users/erik/.stack/setup-exe-cache/x86_64-osx/setup-Simple-Cabal-1.18.1.3-ghc-7.8.3 --builddir=.stack-work/dist/x86_64-osx/Cabal-1.18.1.3 build lib:silk-tag-document --ghc-options " -ddump-hi -ddump-to-file"
    Process exited with code: ExitFailure 1
    Logs have been written to: /Users/erik/Documents/typlab/product/.stack-work/logs/silk-tag-document-0.3.0.1.log

    Preprocessing library silk-tag-document-0.3.0.1...
    <command line>: cannot satisfy -package-id silk-types-1.47-2ad2c3ba67ff5c5bd7cbcf9b7ca338e4
        (use -v for more information)

This doesn't happen on the first build, but it does happen eventually. It has happened on multiple machines here, so I don't think it's tied to one specific setup being broken.

I haven't tried hard to come up with a reproducible case; if you have any ideas what direction I should try, that would help a lot.

[bergmark]

IIRC switching back to an older stack release after getting errors like this works without needing to stack clean.

I saw this for the first time after building from git when #584 was merged (e1000b9) , I can't say whether that's the culprit though.

[mgsloan]

Hmm, this seems serious indeed. By chance, are you using docker while building?

It definitely isn't e1000b9, as that only affects GHCi. My best guess is that it's something squirrely related to #1166 . Are you also using stack test? Could be related to haskell/cabal#2870

[bergmark]

We are not using docker. All these machines are running OS X.

We occasionally use stack test, would it help if I avoided that to see if the error still occurs?

And in general, any debugging tips?

[hesselink]

I've had this without ever running stack with --enable-tests. I've also seen that re-issuing the same command gets a bit further, but eventually it gets stuck. I'll start running some builds in the background today to see if I can get a reproducible case. If I do, I can start bisecting, since it was fine in 0.1.8 and broken in the commit @bergmark linked to.

[bergmark]

i switched back to 0.1.10 and ran a stack clean. After that I made sure to never call stack test or stack build --test.

After I switched branches it caused ~30 local packages to be queued for rebuild and the same style satisfy errors occurred. A few at a time for pretty much every package. In the end it didn't get stuck and everything is now built ok...

[hesselink]

I've got a reproducible case, so I'll start bisecting in the background now.

[hesselink]

OK, bisect is done and says that 7cd87cb is the culprit. It's not clear to me what that commit does and how it could break this. Does this help you? Anything more I can do?

[hesselink]

I've got some more info that might be useful: it seems to be picking the wrong package hash when it fails. If you rerun the command, it picks a different hash for the same package (without rebuilding it) and it works.

Some relevant output lines:

2015-12-14 13:04:37.638271: [info] /usr/bin/ghc --make -fbuilding-cabal-package -O -static -dynamic-too -dynosuf dyn_o -dynhisuf dyn_hi -outputdir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -odir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -hidir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -stubdir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -i -i.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -isrc -i.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build/autogen -I.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build/autogen -I.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -optP-include -optP.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build/autogen/cabal_macros.h -package-name silk-tag-document-0.3.0.1 -hide-all-packages -no-user-package-db -package-db /Users/erik/.stack/snapshots/x86_64-osx/custom-silk-2015-12/7.8.3/pkgdb -package-db /Users/erik/Documents/typlab/product-test/.stack-work/install/x86_64-osx/custom-silk-2015-12/7.8.3/pkgdb -package-db .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/package.conf.inplace -package-id base-noprelude-4.7.0.0.100-d74c112f6faa83662ff2cbc4f28b3cce -package-id containers-0.5.5.1-23e2a2b94d6e452c773209f31d8672c5 -package-id fclabels-2.0.2.3-61022e17851ca1d5dfbd8af8bec0fe51 -package-id hxt-9.3.1.15-612e86fdd53afe84527b9c9d98f728d6 -package-id silk-graph-0.7.0.1-18f1e31592811badbe1e54b997b9a9ac -package-id silk-prelude-0.1-3afceddc65baf06e655c68201e77f08c -package-id silk-types-1.47-3af3b470c5e46cb98ea12ba8453b9664 -package-id text-1.2.1.3-2b2666f8f5002465096b6f348f152d84 -XHaskell2010 Silk.Tag.Document -Wall -ddump-hi -ddump-to-file @(stack_15maE5vLiHaHnQnC7u59lN:Stack.Build.Execute src/Stack/Build/Execute.hs:1310:35)
2015-12-14 13:04:37.753783: [warn] <command line>: cannot satisfy -package-id silk-graph-0.7.0.1-18f1e31592811badbe1e54b997b9a9ac @(stack_15maE5vLiHaHnQnC7u59lN:Stack.Build.Execute src/Stack/Build/Execute.hs:1310:35)
2015-12-14 13:04:37.753892: [warn]     (use -v for more information) @(stack_15maE5vLiHaHnQnC7u59lN:Stack.Build.Execute src/Stack/Build/Execute.hs:1310:35)

...
<re-run>
...

2015-12-14 13:05:24.304417: [info] /usr/bin/ghc --make -fbuilding-cabal-package -O -static -dynamic-too -dynosuf dyn_o -dynhisuf dyn_hi -outputdir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -odir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -hidir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -stubdir .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -i -i.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -isrc -i.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build/autogen -I.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build/autogen -I.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build -optP-include -optP.stack-work/dist/x86_64-osx/Cabal-1.18.1.3/build/autogen/cabal_macros.h -package-name silk-tag-document-0.3.0.1 -hide-all-packages -no-user-package-db -package-db /Users/erik/.stack/snapshots/x86_64-osx/custom-silk-2015-12/7.8.3/pkgdb -package-db /Users/erik/Documents/typlab/product-test/.stack-work/install/x86_64-osx/custom-silk-2015-12/7.8.3/pkgdb -package-db .stack-work/dist/x86_64-osx/Cabal-1.18.1.3/package.conf.inplace -package-id base-noprelude-4.7.0.0.100-d74c112f6faa83662ff2cbc4f28b3cce -package-id containers-0.5.5.1-23e2a2b94d6e452c773209f31d8672c5 -package-id fclabels-2.0.2.3-61022e17851ca1d5dfbd8af8bec0fe51 -package-id hxt-9.3.1.15-612e86fdd53afe84527b9c9d98f728d6 -package-id silk-graph-0.7.0.1-ab8f9b34d205a1ddbf4904e9acef11b2 -package-id silk-prelude-0.1-3afceddc65baf06e655c68201e77f08c -package-id silk-types-1.47-3af3b470c5e46cb98ea12ba8453b9664 -package-id text-1.2.1.3-2b2666f8f5002465096b6f348f152d84 -XHaskell2010 Silk.Tag.Document -Wall -ddump-hi -ddump-to-file @(stack_15maE5vLiHaHnQnC7u59lN:Stack.Build.Execute src/Stack/Build/Execute.hs:1310:35)
...

I've put the full log in this gist. This starts after a stack clean. It builds one of our packages (successfully). Then it makes a (whitespace) change and builds the same package again, failing with the cannot satisfy error. Finally it just reruns the build command and succeeds.

[bergmark]

Cool, i'll use that^ commit for now.

[mgsloan]

@hesselink Awesome, thanks for investigating so thoroughly. The purpose of the commit was to avoid unnecessary reconfigures when the configure options don't change. Either these reconfigures are necessary, or we need to writeBuildCache even if the options don't change.

I've reverted that commit, since it's just an optimization, and one that appears to cause problems... Can y'all please see if this issue is fixed on master?

[bergmark]

sure!

[hesselink]

I just tested with the latest master, and the issue is fixed there, it seems. Thanks!

[mgsloan]

Great!