Skip to content

Something is fishy in RTS's "max pause" GC statistic

While looking into a GC issue, I found a peculiar inconsistency between the +RTS -s output and that from the eventlog.

The -s output is,

  13,756,939,024 bytes allocated in the heap
   6,085,406,120 bytes copied during GC
     182,001,080 bytes maximum residency (22 sample(s))
         753,160 bytes maximum slop
             508 MB total memory in use (0 MB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0     28674 colls, 28674 par    5.268s   2.949s     0.0001s    0.1016s
  Gen  1        22 colls,    21 par    0.004s   0.002s     0.0001s    0.0005s

  Parallel GC work balance: 79.36% (serial 0%, perfect 100%)

  TASKS: 9 (1 bound, 8 peak workers (8 total), using -N2)

  SPARKS: 0 (0 converted, 0 overflowed, 0 dud, 0 GC'd, 0 fizzled)

  INIT    time    0.007s  (  0.017s elapsed)
  MUT     time    4.353s  (  2.556s elapsed)
  GC      time    5.272s  (  2.951s elapsed)
  EXIT    time    0.004s  (  0.072s elapsed)
  Total   time    9.635s  (  5.596s elapsed)

  Alloc rate    3,160,479,659 bytes per MUT second

  Productivity  45.2% of total user, 47.0% of total elapsed

Note the "Max pause" statistic: gen0 apparently pauses for four orders of magnitude more than gen1. This seems rather hard to believe.

Moreover, if I open the eventlog from the same run in threadscope, I find,

Generation Collections Par collections Elapsed time Avg pause Max pause
GC Total 27215 25518 2.83s 0.0001s 0.1016s
Gen 0 25504 25504 1.55s 0.0001s 0.0012s
Gen 1 15 14 0.99s 0.0657s 0.1016s

Hmmmmmmmmm...

Trac metadata
Trac field Value
Version 8.2.1
Type Bug
TypeOfFailure OtherFailure
Priority normal
Resolution Unresolved
Component Runtime System
Test case
Differential revisions
BlockedBy
Related
Blocking
CC
Operating system
Architecture
To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information