[Haskell-cafe] Weird multi-threading runtime behaviour of single-threaded program with GHC-7.0.3

Herbert Valerio Riedel hvr at gnu.org
Fri Apr 1 12:37:09 CEST 2011


I'm experiencing an unexpected behaviour with GHC-7.0.3/x86_64's
multithreading runtime when running some more demanding single-thread

I've isolated the part of the larger application which exposes the
problem down to the parsing of a ~8MiB JSON file which causes quite a
bit of memory allocations (source at end of email). The program is
compiled with

ghc --make -O2 -threaded -eventlog -rtsopts parse_aeson.hs

and I ran it with and w/o the -N12 option on a 12-core machine (the
problem is visible on a 4-core machine as well):

$ time ./parse_aeson test.json
0.000392s after readFile
0.001016s parse was a success...
6.050836s NFed parse-tree...
6.050968s NFed parse-tree...
no exception

real    0m6.100s
user    0m5.680s
sys     0m0.419s

$ time ./parse_aeson test.json +RTS -N12
0.001249s after readFile
0.001777s parse was a success...
10.048607s NFed parse-tree...
10.048738s NFed parse-tree...
no exception

real    0m10.125s
user    0m57.496s
sys     0m39.927s

When observing top(1)'s output, I saw that all HECs consumed a
substantial amount of cpu cycle, so I loaded up threadscope to see what
the remaining 11 HECs were doing all the time.

I've put the resulting eventlog files and screenshots of threadscope's
visualization online at



What's happening there? The actual processing work seems to be done in a
single HEC... but what are the remaining 11 HECs doing exactly? Am I
doing something wrong?

What does it mean when the GC-bars in threadscope becomes green as in
the middle of the screenshot below?


-- also available at http://www.narf.at/~hvr/Haskell/parse_aeson.hs

module Main where

import Control.DeepSeq
import Control.Exception
import Data.Aeson
import Data.Time
import System.Environment
import qualified Data.Attoparsec.Lazy as APL
import qualified Data.ByteString.Lazy.Char8 as LB

parseIt :: FilePath -> IO ()
parseIt fn = do
  t0 <- getCurrentTime

  let putStrLn' !s = do
        t0' <- getCurrentTime
        putStrLn $ show (t0' `diffUTCTime` t0) ++ " " ++ s

  json_text <- LB.readFile fn

  putStrLn' "after readFile"
  let Success p = decode json_text :: Result Value
  putStrLn' "parse was a success..."
  putStrLn' $ p `deepseq` "NFed parse-tree..."
  putStrLn' $ p `deepseq` "NFed parse-tree..."

decode :: FromJSON a => LB.ByteString -> Result a
decode = either Error fromJSON . APL.eitherResult . APL.parse json

main :: IO ()
main = do
  fns <- getArgs
  case fns of
    [fn] -> do
      res <- try $ parseIt fn
      case res of
        Left e -> putStrLn $ "caught: " ++ show (e :: SomeException)
        Right () -> putStrLn "no exception"

    _    -> putStrLn "usage: parse_aeson <json-file>"

More information about the Haskell-Cafe mailing list