[GHC] #14445: GC timing stats (e.g. mutator_elapsed_ns) decrease over time

[GHC]

#14445: GC timing stats (e.g. mutator_elapsed_ns) decrease over time
-------------------------------------+-------------------------------------
           Reporter:  harendra       |             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:  Debugging
  Unknown/Multiple                   |  information is incorrect
          Test Case:                 |        Blocked By:
           Blocking:                 |   Related Tickets:
Differential Rev(s):                 |         Wiki Page:
-------------------------------------+-------------------------------------
 See this measurement code here in the `gauge` benchmarking tool, which is
 a clone of the criterion benchmarking tool.
 : https://github.com/harendra-kumar/hs-
 gauge/blob/f8c9bcd6ee03c3090f110664ff279a20f2da9130/Gauge/Measurement.hs#L315
 . This code displays debug prints when the end time is lower than the
 start time for `mutator_elapsed_ns`.

 When we run this benchmark defined in https://github.com/harendra-kumar
 /hs-gauge/blob/f8c9bcd6ee03c3090f110664ff279a20f2da9130/benchs/GCBug.hs
 the following output is produced:

 {{{
 $ stack bench --benchmark-arguments "--quick"
 gauge-0.1.3: benchmarks
 Running 1 benchmarks...
 Benchmark gcbug: RUNNING...
 benchmarking streamingDecreased by: 25818791 : s = 59840178 e = 34021387
 Decreased by: 22707134 : s = 76706673 e = 53999539
 Decreased by: 4776100 : s = 96201146 e = 91425046
 streaming                                time                 50.00 ms

 benchmarking pipesDecreased by: 12487955 : s = 153949495 e = 141461540
 pipes                                    time                 50.00 ms

 benchmarking conduitDecreased by: 5523916 : s = 310913002 e = 305389086
 conduit                                  time                 50.00 ms

 Benchmark gcbug: FINISH

 }}}

 Notice the "Decreased by" getting printed quite a few times. I have found
 it to be more likely for these particular libraries i.e. streaming, pipes
 and conduit; so I have used only these in the benchmarking file
 `GCBug.hs`. I tried some other streaming libraries as well but it did not
 occur often in those cases. In these cases it occurs almost every time. I
 am running it on a macbook.

 The repository is here: https://github.com/harendra-kumar/hs-gauge/tree
 /gc-bug . The branch in the repo is `gc-bug`. You can run the benchmark
 named `gcbug` using the command `stack bench --benchmark-arguments "--
 quick"` to reproduce the output above.

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