Bug in RTS GC stats reporting?

[Julian Seward (Intl Vendor)]

Duh.  Cancel my last comment.  As Nicholas says, the code is
wrong for all platforms.

J

| -----Original Message-----
| From: Julian Seward (Intl Vendor) [mailto:v-julsew at microsoft.com] 
| Sent: Thursday, November 01, 2001 5:43 PM
| To: Nicholas Nethercote; glasgow-haskell-bugs at haskell.org
| Subject: RE: Bug in RTS GC stats reporting?
| 
| 
| 
| Problem is (I think) that this is already correct on some 
| platforms, but not all.  There may be a missing scaling at 
| some point upstream for some platforms.  Precisely what ghc 
| version is this and what 
| platform are you running on?
| 
| J
| 
| | -----Original Message-----
| | From: Nicholas Nethercote [mailto:njn25 at cam.ac.uk]
| | Sent: Thursday, November 01, 2001 4:37 PM
| | To: glasgow-haskell-bugs at haskell.org
| | Subject: Bug in RTS GC stats reporting?
| | 
| | 
| | Hi,
| | 
| | I think there's a bug in the reporting of GC stats.  For
| | example, when running the nofib program imaginary/x2n1, I get 
| | this output:
| | 
| |  41,864,696 bytes allocated in the heap
| |   1,688,656 bytes copied during GC
| |     764,280 bytes maximum residency (2 sample(s))
| | 
| |         155 collections in generation 0 (  0.14s)
| |           2 collections in generation 1 (  0.01s)
| | 
| |           2 Mb total memory in use
| | 
| |   INIT  time    0.00s  (  0.00s elapsed)
| |   MUT   time    0.26s  (  0.26s elapsed)
| |   GC    time    0.15s  (  0.15s elapsed)
| |   EXIT  time    0.00s  (  0.00s elapsed)
| |   Total time    0.41s  (  0.41s elapsed)
| | 
| |   %GC time       0.4%  (0.4% elapsed)
| | 
| |   Alloc rate    161,018,061 bytes per MUT second
| | 
| |   Productivity  63.4% of total user, 63.4% of total elapsed
| | 
| | Notice the "%GC time" field: I don't think 0.15s is 0.4% of 0.41s.
| | 
| | If you look at ghc/rts/Stats.c line 576 (this recent version:
| | $Id: Stats.c,v 1.32 2001/08/14 13:40:09 sewardj Exp $) the 
| | offending lines are:
| | 
| |             fprintf(sf, "  %%GC time     %5.1f%%  (%.1f%% 
| | elapsed)\n\n",
| |                     TICK_TO_DBL(GC_tot_time)*100/time,
| |                     TICK_TO_DBL(GCe_tot_time)*100/etime);
| | 
| | Here GC_tot_time, GCe_tot_time, time, and etime are all of
| | type TICK_TYPE, but only the first two are being converted to 
| | seconds.  If you change it to this:
| | 
| |             fprintf(sf, "  %%GC time     %5.1f%%  (%.1f%% 
| | elapsed)\n\n",
| |                     TICK_TO_DBL(GC_tot_time)*100/TICK_TO_DBL(time),
| |                     
| TICK_TO_DBL(GCe_tot_time)*100/TICK_TO_DBL(etime));
| | 
| | The results are much better, viz:
| | 
| |  41,864,696 bytes allocated in the heap
| |   1,688,656 bytes copied during GC
| |     764,280 bytes maximum residency (2 sample(s))
| | 
| |         155 collections in generation 0 (  0.17s)
| |           2 collections in generation 1 (  0.01s)
| | 
| |           2 Mb total memory in use
| | 
| |   INIT  time    0.00s  (  0.00s elapsed)
| |   MUT   time    0.24s  (  0.24s elapsed)
| |   GC    time    0.18s  (  0.18s elapsed)
| |   EXIT  time    0.00s  (  0.00s elapsed)
| |   Total time    0.42s  (  0.42s elapsed)
| | 
| |   %GC time      42.9%  (42.9% elapsed)
| | 
| |   Alloc rate    174,436,233 bytes per MUT second
| | 
| |   Productivity  57.1% of total user, 57.1% of total elapsed
| | 
| | Unless I'm completely misinterpreting the intended meaning of
| | "%GC time"...
| | 
| | Tell me if you want more information, although I wouldn't think so.
| | --
| | Nick Nethercote
| | njn25 at cam.ac.uk
| | 
| | 
| | _______________________________________________
| | Glasgow-haskell-bugs mailing list
| | Glasgow-haskell-bugs at haskell.org 
| | http://www.haskell.org/mailman/listinfo/glasgo| w-haskell-bugs
| | 
| 
| _______________________________________________
| Glasgow-haskell-bugs mailing list
| Glasgow-haskell-bugs at haskell.org
| http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs
|