
Hello, I'm experiencing an unexpected behaviour with GHC-7.0.3/x86_64's multithreading runtime when running some more demanding single-thread computations. 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 http://www.narf.at/~hvr/Haskell/parse_aeson.N0.eventlog.png http://www.narf.at/~hvr/Haskell/parse_aeson.N0.eventlog.xz http://www.narf.at/~hvr/Haskell/parse_aeson.N12.eventlog.png http://www.narf.at/~hvr/Haskell/parse_aeson.N12.eventlog.xz 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? http://www.narf.at/~hvr/Haskell/parse_aeson.N4.eventlog.pdf ------------------------------------------------------------------------- -- 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>"