Why does this code consume so much heap?

Question

Here is the full repository. This is a very simple test which inserts 50000 random things into the database with the postgresql-simple database binding. It uses MonadRandom and can generate Things lazily.

Here is the lazy Thing generator.

Here is case1 and specific snippet of code using Thing generator:

insertThings c = do
  ts <- genThings
  withTransaction c $ do
    executeMany c "insert into things (a, b, c) values (?, ?, ?)" $ map (\(Thing ta tb tc) -> (ta, tb, tc)) $ take 50000 ts

Here is case2, which just dumps Things to stdout:

main = do
  ts <- genThings
  mapM print $ take 50000 ts

In the first case I have very bad GC times:

cabal-dev/bin/posttest +RTS -s       
   1,750,661,104 bytes allocated in the heap
     619,896,664 bytes copied during GC
      92,560,976 bytes maximum residency (10 sample(s))
         990,512 bytes maximum slop
             239 MB total memory in use (0 MB lost due to fragmentation)

                                    Tot time (elapsed)  Avg pause  Max pause
  Gen  0      3323 colls,     0 par   11.01s   11.46s     0.0034s    0.0076s
  Gen  1        10 colls,     0 par    0.74s    0.77s     0.0769s    0.2920s

  INIT    time    0.00s  (  0.00s elapsed)
  MUT     time    2.97s  (  3.86s elapsed)
  GC      time   11.75s  ( 12.23s elapsed)
  RP      time    0.00s  (  0.00s elapsed)
  PROF    time    0.00s  (  0.00s elapsed)
  EXIT    time    0.00s  (  0.00s elapsed)
  Total   time   14.72s  ( 16.09s elapsed)

  %GC     time      79.8%  (76.0% elapsed)

  Alloc rate    588,550,530 bytes per MUT second

  Productivity  20.2% of total user, 18.5% of total elapsed

While in the second case times are great:

cabal-dev/bin/dumptest +RTS -s > out
   1,492,068,768 bytes allocated in the heap
       7,941,456 bytes copied during GC
       2,054,008 bytes maximum residency (3 sample(s))
          70,656 bytes maximum slop
               6 MB total memory in use (0 MB lost due to fragmentation)

                                    Tot time (elapsed)  Avg pause  Max pause
  Gen  0      2888 colls,     0 par    0.13s    0.16s     0.0001s    0.0089s
  Gen  1         3 colls,     0 par    0.01s    0.01s     0.0020s    0.0043s

  INIT    time    0.00s  (  0.00s elapsed)
  MUT     time    2.00s  (  2.37s elapsed)
  GC      time    0.14s  (  0.16s elapsed)
  RP      time    0.00s  (  0.00s elapsed)
  PROF    time    0.00s  (  0.00s elapsed)
  EXIT    time    0.00s  (  0.00s elapsed)
  Total   time    2.14s  (  2.53s elapsed)

  %GC     time       6.5%  (6.4% elapsed)

  Alloc rate    744,750,084 bytes per MUT second

  Productivity  93.5% of total user, 79.0% of total elapsed

I have tried to apply heap profiling, but did not understand anything. It looks like all of 50000 Thing are constructed in memory first, then transformed into ByteStrings with queries and then these strings are sent to the database. But why does it happen? How do I determine the guilty code?

GHC version is 7.4.2

Compilations flags is -O2 for all libraries and package itself (compiled by cabal-dev in sandbox)

Answer 1

I've checked profile with formatMany and 50k Things. Memory builds up steadily and then quickly drops. Maximum memory used is slightly over 40mb. Main cost centers are buildQuery and escapeStringConn followed by toRow. Half of data are ARR_WORDS (byte strings), Actions and lists.

formatMany pretty much makes one long ByteString from pieces assembled from nested lists of Actions. Actions are converted to ByteString Builders, which retain ByteStrings until used to produce final long strict ByteString. These ByteStrings live long life up until final BS is constructed.

The strings need to be escaped with libPQ, so any non Plain action BS is passed to libPQ and replaced with new one in escapeStringConn and friends, adding more garbage. If you replace Text in Thing with another Int, GC time drops from 75% to 45%.

I've tried to lessen use of temporary lists by formatMany and buildQuery, replacing mapM with foldM over Builder. It does not help much but increases code complexity a bit.

TLDR - Builders can't be consumed lazily because all of them are needed to produce final strict ByteString (pretty much array of bytes). If you have problem with memory, split executeMany into chunks inside same transaction.