confusing space use and space profiles.

[Simon Marlow]

Duncan Coutts wrote:
> I'm totally confused by the space profiling. Let me explain.
> 
> Here's a simple log file processing program. It prints the 10 most
> frequently occurring lines in a file.
> 
> import Data.List
> import qualified Data.Map as Map
> import qualified Data.ByteString.Lazy.Char8 as BS
> 
> main = BS.interact
>      $ BS.unlines
>      . map fst
>      . take 10
>      . sortBy (comparingReversed snd)
>      . Map.toList
>      . foldl' accumulate Map.empty
>      . BS.lines
> where accumulate map line =
>          Map.insertWith (\_ n -> n+1) line 1 map
>        comparingReversed f a b = f b `compare` f a
> 
> 
> Here I'm using ByteString.Lazy because it's faster than ByteString.
> That's probably because it allows us to consume the input incrementally.
> 
> However using ByteString.Lazy uses much more space than when using
> strict ByteString. For an 11Mb log file:
>       * the strict version needs at least 18Mb heap (and takes 8.5s)
>       * the lazy version needs at least 55Mb heap (and takes 1.9s)
> 
> This is surprising as I would have expected nearly the same space use.
> The lazy version will use more cons cells and PS constructors but this
> should still be fairly negligible as it reads in 32k chunks.
> 
> So I tried memory profiling with the lazy version. Using -hc or -hd
> indicates that we are only using about 27Mb which is just what I would
> have expected, furthermore the breakdown by cost centre and closure is
> about what I would have expected. In particular the ARR_WORDS closure
> type which is for the #MutableByteArray is exactly the size of the file
> that was read. The PS and (:) closures take a fair amount which is
> because there's one per line in the file, and the lines are not that
> long on average. The Bin constructors of the finite map take much of the
> rest.
> 
> So if the heap profile says that we're using at most 27Mb then why does
> the program run out of heap when allowed any less than 55Mb ?
>
> This seems suspiciously close to a factor of 2.

Make sure you add "+RTS -xt" to get the stack included in the profile (it isn't 
by default), and also remember that profiling overheads are included in the real 
heap residency but not in the profile.  Profiling overheads are currently 2 
words (16 bytes on x86_64) per closure.

> At first I suspected that it might be that we were inefficiently
> allocating chunks, but we're reading from stdin in chunks of size:
> 
> defaultChunkSize :: Int
> defaultChunkSize = 32 * k - overhead
>    where k = 1024
>          overhead = 2 * sizeOf (undefined :: Int)
> 
> which should be reasonable I think and not give us lots of half used
> memory blocks. All other strings we create are substrings so share space
> and only take space for the PS and (:) constructors.
> 
> 
> Ok, here's an odd thing. When profiling the strict version, the -hd
> closure description doesn't show the ARR_WORDS closure type at all. But
> there should be one great big 11Mb MutableByteArray#. It shows the other
> closure types taking about 13Mb. Did I guess wrong about what ARR_WORDS
> means?

Hmm.  Do you mean the magnitude of the profile seems reasonable, but its 
contents are not what you expect?  What does the profile include instead of the 
ARR_WORDS you were expecting?

> I was doing all this with ghc-6.5.20060724 on amd64. I got essentially
> the same results with ghc-6.4.2.
> 
> The only profiling option that shows the full heap size was biographical
> profiling. The hp2ps plot from using -hb peaked at 55Mb. In ghc-6.4.2 it
> was all marked as drag. I'm not exactly sure what that means.

drag means closures that are never going to be used, but which are retained by 
something else.

 > With
> ghc-6.5.20060724 I got a bit of all the categories: drag,
> inherent_in_use, void, lag and use. Again it peaks at 55Mb with drag the
> dominant one. With the strict ByteString it peaks at about 16M.

Could be that biographical profiling isn't subtracting the profiling overhead as 
it should.  I'll see if I can spot any mistakes in the code.

Cheers,
	Simon