[GHC] #14486: Something is fishy in RTS's "max pause" GC statistic

#14486: Something is fishy in RTS's "max pause" GC statistic -------------------------------------+------------------------------------- Reporter: bgamari | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: Component: Runtime | Version: 8.2.1 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: -------------------------------------+------------------------------------- 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... -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/14486 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#14486: Something is fishy in RTS's "max pause" GC statistic -------------------------------------+------------------------------------- Reporter: bgamari | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: Component: Runtime System | Version: 8.2.1 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by bgamari): Ahh, I think this may actually be another manifestation of #14445 and therefore fixed by d9f0c24dd01b2f2a9a5ccc2fc45e93064d4ba0c1. Confirming now. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/14486#comment:1 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#14486: Something is fishy in RTS's "max pause" GC statistic -------------------------------------+------------------------------------- Reporter: bgamari | Owner: (none) Type: bug | Status: closed Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 8.2.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * cc: duog (added) * status: new => closed * resolution: => fixed * milestone: => 8.4.1 Comment: Indeed it's fixed in HEAD. Good work, duog! -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/14486#comment:2 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler
participants (1)
-
GHC