[GHC] #16102: forkProcess causes weird GC summary in the forked process

28 Dec 2018

      #16102: forkProcess causes weird GC summary in the forked process
-------------------------------------+-------------------------------------
           Reporter:  osa1           |             Owner:  (none)
               Type:  bug            |            Status:  new
           Priority:  normal         |         Milestone:
          Component:  Runtime        |           Version:  8.6.3
  System                             |
           Keywords:                 |  Operating System:  Unknown/Multiple
       Architecture:                 |   Type of failure:  None/Unknown
  Unknown/Multiple                   |
          Test Case:                 |        Blocked By:
           Blocking:                 |   Related Tickets:
Differential Rev(s):                 |         Wiki Page:
-------------------------------------+-------------------------------------
 The existing test `forkprocess01` actually exhibits this behavior, but we
 just don't have the necessary assertions in place to catch it. One of the
 assertions I added in https://gitlab.haskell.org/ghc/ghc/merge_requests/51
 catches this bug.

 Here's the output with GHC 8.4:

 {{{
 $ ghc forkprocess01.hs -debug -rtsopts
 [1 of 1] Compiling Main             ( forkprocess01.hs, forkprocess01.o )
 Linking forkprocess01 ...

 $ ./forkprocess01 +RTS -s
           44,144 bytes allocated in the heap
            4,824 bytes copied during GC
           37,696 bytes maximum residency (1 sample(s))
           19,648 bytes maximum slop
                2 MB total memory in use (0 MB lost due to fragmentation)

                                      Tot time (elapsed)  Avg pause  Max
 pause
   Gen  0         0 colls,     0 par    0.000s   0.000s     0.0000s
 0.0000s
   Gen  1         1 colls,     0 par    0.001s   0.001s     0.0006s
 0.0006s

   INIT    time    0.000s  (  0.000s elapsed)
   MUT     time    0.000s  (  0.001s elapsed)
   GC      time    0.001s  (  0.001s elapsed)
   EXIT    time    0.000s  (  0.000s elapsed)
   Total   time    0.000s  (  0.002s elapsed)

   %GC     time     61200000.0%  (32.3% elapsed)

   Alloc rate    0 bytes per MUT second

   Productivity -100999900.0% of total user, 47.2% of total elapsed

 Just (Exited (ExitFailure 72))
           54,160 bytes allocated in the heap
            3,480 bytes copied during GC
           44,576 bytes maximum residency (1 sample(s))
           25,056 bytes maximum slop
                2 MB total memory in use (0 MB lost due to fragmentation)

                                      Tot time (elapsed)  Avg pause  Max
 pause
   Gen  0         0 colls,     0 par    0.000s   0.000s     0.0000s
 0.0000s
   Gen  1         1 colls,     0 par    0.001s   0.001s     0.0005s
 0.0005s

   INIT    time    0.000s  (  0.000s elapsed)
   MUT     time    0.001s  (  0.003s elapsed)
   GC      time    0.001s  (  0.001s elapsed)
   EXIT    time    0.000s  (  0.000s elapsed)
   Total   time    0.002s  (  0.004s elapsed)

   %GC     time      32.0%  (14.5% elapsed)

   Alloc rate    87,073,954 bytes per MUT second

   Productivity  43.3% of total user, 74.6% of total elapsed
 }}}

 Notice the `-100999900.0%` productivity in the first summary, which is
 printed by the child process.

-- 
Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/16102
GHC http://www.haskell.org/ghc/
The Glasgow Haskell Compiler