Bug that locks up all CPUs on machine at 100%

[thomasjm]

I'm experiencing a really weird problem where a small Haskell program using hslogger will livelock and use all of the (8) CPUs on my laptop at 100%. I'm not totally sure that hslogger is to blame but it definitely seems to be part of the interaction that is happening, and I'd greatly appreciate any help.

The full repro can be found here: https://github.com/thomasjm/haskell-livelock-repro. You can simply clone this repo and run stack install && high-cpu-debug-exe.

Here's the code and the debugging I've attempted:

main :: IO ()
main = do
  -- Remove the default handler and set our own.
  -- If you use the default handler, the problem doesn't happen.
  updateGlobalLogger rootLoggerName removeHandler
  handler <- streamHandler stderr DEBUG
  -- If the message is just "$msg" instead of "Msg: $msg", the problem doesn't happen
  updateGlobalLogger rootLoggerName (addHandler $ setFormatter handler $ simpleLogFormatter "Msg: $msg")
  let logFn = warningM "MyApp"

  -- Repeat this 20 times
  replicateM_ 20 $ do
    logFn [i|Spawning spawnWithPty|]
    forkIO $ do
      logFn [i|Doing spawnWithPty|]
      void $ spawnWithPty Nothing True "sleep" ["99999999"] (80, 24)

    logFn [i|Spawning readCreateProcess|]
    forkIO $ void $ do
      logFn [i|Doing readCreateProcess|]
      liftIO $ readCreateProcess (proc "echo" ["hi"]) ""

  -- All CPUs should now be stuck at 100%
  threadDelay 60000000

This program sets up a simple log handler that prints to stderr. Then it runs a loop where it forks threads that do either spawnWithPty (to create a new process inside a pseuo-terminal) or readCreateProcess (to create a normal process). I know this is weird, but if you remove either of these then it doesn't trigger the problem.

• I've tried profiling with +RTS -p h but the profiling report doesn't show anything about the massive amount of CPU time being wasted (!)
• I've tried compiling with DWARF symbols and using perf to record the top symbols. 90% of the time is being spent in gcWorkerThread but I'm not sure what to make of that fact.
• I've tried compiling with -debug and running with +RTS -v to see the runtime logging, but I haven't gotten any insight from that.
• I know that spawnWithPty does FFI to create new pseudo-terminals, and my current theory is that some kind of multithreading/FFI race condition is happening.

[hvr]

Can this also be reproduced without requiring the use of non-standard tooling such as stack install? Unfortunately my time budget is too limited to be able to deal with 3rd party build tools so I'd ask you to please provide repro instructions in accordance with the contribution guidelines which for this very reason state

Reproduction-instructions shall be expressed in terms of Haskell.org's standard tooling (i.e. cabal).

[thomasjm]

Ah sorry, missed that guideline. Actually I think this issue can be closed -- I posted about this on Reddit and someone simplified the repro to remove hslogger: https://www.reddit.com/r/haskell/comments/d4h7ty/why_does_this_code_livelock_all_my_cpus_at_100/. Seems it's related to the FFI/forking in the other library.

Closing now, sorry for the noise...