Perf regression: ghc --make: add nicer names to RTS threads (threaded IO manager, make workers) (f686682)

[Sergei Trofimovich]

On Thu, 07 Aug 2014 15:42:07 +0100
Simon Marlow <marlowsd at gmail.com> wrote:

> On 06/08/2014 21:40, Sergei Trofimovich wrote:
> > I think I know what happens. According to perf the benchmark spends 34%+
> > of time in garbage collection ('perf record -- $args'/'perf report'):
> >
> >    27,91%  test  test               [.] evacuate
> >     9,29%  test  test               [.] s9Lz_info
> >     7,46%  test  test               [.] scavenge_block
> >
> > And the whole benchmark runs a tiny bit more than 300ms.
> > It is exactly in line with major GC timer (0.3s).
> 
> 0.3s is the *idle* GC timer, it has no effect when the program is 
> running normally.  There's no timed GC or anything like that.
> 
> It sometimes happens that a tiny change somewhere tips a program over 
> into doing one more major GC, though.
> 
> > If we run
> >      $ time ./test inverter 345 10n 4u 1>/dev/null
> > multiple times there is heavy instability in there (with my patch reverted):
> >      real    0m0.319s
> >      real    0m0.305s
> >      real    0m0.307s
> >      real    0m0.373s
> >      real    0m0.381s
> > which is +/- 80ms drift!
> >
> > Let's try to kick major GC earlier instead of running right at runtime
> > shutdown time:
> >      $ time ./test inverter 345 10n 4u +RTS -I0.1 1>/dev/null
> >
> >      real    0m0.304s
> >      real    0m0.308s
> >      real    0m0.302s
> >      real    0m0.304s
> >      real    0m0.308s
> >      real    0m0.306s
> >      real    0m0.305s
> >      real    0m0.312s
> > which is way more stable behaviour.
> >
> > Thus my theory is that my changed stepped from
> >    "90% of time 1 GC run per run"
> > to
> >    "90% of time 2 GC runs per run"
> 
> Is this program idle?  I have no idea why this might be happening!  If 
> the program is busy computing stuff, the idle GC should not be firing. 
> If it is, that's a bug.

The task is a completely CPU-bound thing.

Then I was very lucky to get that change with -I option.
I'll try to find exact place where profiling times change (or just float),
but it will take more time.

-- 

  Sergei
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 181 bytes
Desc: not available
URL: <http://www.haskell.org/pipermail/ghc-devs/attachments/20140810/54be5c27/attachment.sig>