GC timing stats (e.g. mutator_elapsed_ns) decrease over time
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
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.