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

"stdout" test stalls temporarily sometimes #478

Closed
chrismwendt opened this issue Feb 20, 2022 · 3 comments · Fixed by #480
Closed

"stdout" test stalls temporarily sometimes #478

chrismwendt opened this issue Feb 20, 2022 · 3 comments · Fixed by #480

Comments

@chrismwendt
Copy link
Contributor

chrismwendt commented Feb 20, 2022

When running the tests for cabal, I noticed it hangs 20% of the time on the stdout test:

prop "stdout" $ \ (vals :: [String]) -> do
let expected = concat vals
(actual, ()) <- hCapture [IO.stdout] $ runConduit $ yieldMany (map T.pack vals) .| encodeUtf8C .| stdoutC
actual `shouldBe` expected

$ stack test conduit
...
  sinkFile
  sinkHandle
  sinkIOHandle
  print
    +++ OK, passed 100 tests.
82/100 <--- stalls here

That 82/100 is coming from where hspec prints test progress which prints asynchronously while looping through 100 examples generated by QuickCheck. The test sometimes captures output from a concurrent hspec stdout write and fails:

image

Although I couldn't repro by injecting failures, I think that because of QuickCheck's shrinking, it keeps trying to find an input that fails again after it hits a failure (it never will because progress won't be printed), and the memory usage skyrockets to over 26GB:

image

After the test stopped or got killed, the total memory usage on my system dropped back down:

image

I captured a heap profile with ghcoptions: -Wall -rtsopts -with-rtopts=-h, and the memory rose (very slowly, I stopped it after a couple minutes):

image

Environment:

  • Apple M1 macOS 12.0.1
  • stack --version prints Version 2.7.3, Git revision 7927a3aec32e2b2e5e4fb5be76d0d50eddcc197f x86_64 hpack-0.34.4
  • On commit f371e82
@chrismwendt
Copy link
Contributor Author

chrismwendt commented Feb 20, 2022

Workarounds/solutions:

  • Specify a different hspec formatter that doesn't print to stdout while the test is running, but it's unintuitive for the test passing to depend on which test framework formatter you're using.
  • The test could run in a subprocess so that it has a different stdout. That's a pretty heavyweight solution.
  • Put the test behind a flag like --enable-stdout-tests and default to disabled.
  • Always run stack test conduit | cat to trick hspec into disabling progress since it checks for NO_COLOR and a terminal

@snoyberg
Copy link
Owner

stdoutC is a thin wrapper around sinkHandle. It's probably best to simply skip this test and rely on tests of sinkHandle instead. I'd accept a PR for this. However, I've never experienced this behavior myself, and it may indicate that there are issues elsewhere. I don't think conduit is the culprit here.

@chrismwendt
Copy link
Contributor Author

chrismwendt commented Feb 21, 2022

The timer ticks at 0.05s intervals, so slower machines are more likely to encounter the error (maybe yours is fast). It's moreso the conflicting uses of stdout between hspec and the conduit tests than one or the other individually that's causing this issue. PR: #480

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants