[m-dev.] efficiency situation with file offset tracking

[Fergus Henderson]

On 11-Feb-2000, Robert_William HUTTON <rwh at ecr.mu.oz.au> wrote:
> On Thu, 10 Feb 2000, Fergus Henderson wrote:
> > On 10-Feb-2000, Robert_William HUTTON <rwh at ecr.mu.oz.au> wrote:
> > > Well, after much stuffing around and many recompilations due to
> > > home/mercury0 being full, I have managed to profile cat.m with and without
> > > file offset tracking in io.m.  The top parts of the profiles follow.
> > 
> > So that's what, 8% slow-down?, for a program spending almost all it's time
> > doing I/O.  That's probably acceptable.
> > 
> > It might be good to also check the overhead for a version of cat that
> > does I/O character at a time (via io__read_char) rather than line at
> > a time (via io__read_line_as_string).  If that is not significantly
> > worse, then I'd say go ahead and commit this change.
> 
> For a version of cat that uses io__read_char and io__write_char:
> 
> Without changes to io.m:
>    %  cumulative    self              self    total
>  time    seconds  seconds    calls  ms/call  ms/call name
>  62.1       2.55     2.55  8846154     0.00     0.00 <predicate
> io:'read_char'/3 mode 0> [4] 
>  21.9       3.45     0.90  8846153     0.00     0.00 <predicate
> io:'write_char'/3 mode 0> [5] 
>  15.8       4.10     0.65        1   650.00  4100.00 <predicate
> cat:'cat'/2 mode 0> [3] 
> 
> With changes to io.m:
>  67.3       3.10     3.10  8846154     0.00     0.00 <predicate
> io:'read_char'/3
>  mode 0> [4] 
>  20.6       4.05     0.95  8846153     0.00     0.00 <predicate
> io:'write_char'/
> 3 mode 0> [5] 
>  11.9       4.60     0.55        1   550.00  4600.00 <predicate
> cat:'cat'/2 mode
>  0> [3] 

It would actually be better to just measure the overall slow-down,
without enabling profiling.  It's the overall slow-down figure that
I'm interested in, mostly.  Enabling profiling will skew the results somewhat.  

> This seems to be pretty consistent with the previous profiling I did with
> the version of cat that uses io__read_line_as_string.

Well, the slow-down looks a bit worse in this case -- about 12%,
by my calculation, although you should be able to compute it more
accurately.

An interesting point is that most of the time spent in io__read_char
is probably spent doing memory allocation (which includes GC time).
If you compile with intermodule optimization enabled, the compiler
should hopefully be able to do deforestation optimization and to
thus eliminate the memory allocation.  That will speed the program up
significantly, and as a result increase the relative slowdown
from your change.

-- 
Fergus Henderson <fjh at cs.mu.oz.au>  |  "I have always known that the pursuit
WWW: <http://www.cs.mu.oz.au/~fjh>  |  of excellence is a lethal habit"
PGP: finger fjh at 128.250.37.3        |     -- the last words of T. S. Garp.
--------------------------------------------------------------------------
mercury-developers mailing list
Post messages to:       mercury-developers at cs.mu.oz.au
Administrative Queries: owner-mercury-developers at cs.mu.oz.au
Subscriptions:          mercury-developers-request at cs.mu.oz.au
--------------------------------------------------------------------------