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

#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

#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 System | Version: 8.2.1 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Debugging | Unknown/Multiple information is incorrect | Test Case: Blocked By: | Blocking: Related Tickets: #14257, #14006, | Differential Rev(s): #11645 | Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * related: => #14257, #14006, #11645 Comment: This may be related to the issues seen elsewhere with profiling (e.g. #14257, #14006, #11645). -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/14445#comment:1 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#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 System | Version: 8.2.1 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Debugging | Unknown/Multiple information is incorrect | Test Case: Blocked By: | Blocking: Related Tickets: #14257, #14006, | Differential Rev(s): #11645 | Wiki Page: | -------------------------------------+------------------------------------- Comment (by duog): I observed this bug, then applied Phab:D4184, and it seems to fix it. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/14445#comment:2 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#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 System | Version: 8.2.1
Resolution: | Keywords:
Operating System: Unknown/Multiple | Architecture:
Type of failure: Debugging | Unknown/Multiple
information is incorrect | Test Case:
Blocked By: | Blocking:
Related Tickets: #14257, #14006, | Differential Rev(s):
#11645 |
Wiki Page: |
-------------------------------------+-------------------------------------
Comment (by Ben Gamari

#14445: GC timing stats (e.g. mutator_elapsed_ns) decrease over time -------------------------------------+------------------------------------- Reporter: harendra | 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: Type of failure: Debugging | Unknown/Multiple information is incorrect | Test Case: Blocked By: | Blocking: Related Tickets: #14257, #14006, | Differential Rev(s): #11645 | Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * status: new => closed * resolution: => fixed * milestone: => 8.4.1 -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/14445#comment:4 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler
participants (1)
-
GHC