bug#12033: closed (Re: bug#12033: format should be faster)

[nalaginrut <nalaginrut@gmail.com>]

On Tue, 2012-08-21 at 00:37 +0200, Ludovic Courtès wrote: 
> I wrote:
> 
> > Note that (ice-9 format) is an order of magnitude slower, though:
> >
> > scheme@(guile-user)> (f 4000)
> > clock utime stime cutime cstime gctime
> > 260.14 258.94  0.51   0.00   0.00  63.19
> > $1 = #f
> >
> > Admittedly, this should be fixed, but that’s another story...
> 
> A bit of profiling shows this:
> 
> --8<---------------cut here---------------start------------->8---
> scheme@(guile-user)> ,pr (with-output-to-port (%make-void-port "w") (lambda () (let loop ((i 40000)) (or (zero? i) (begin (format #t "~a ~a~%" 'foo 'bar) (loop (1- i)))))))
> %     cumulative   self             
> time   seconds     seconds      name
>  15.70      2.13      0.34  format
>  10.74      1.39      0.23  tilde-dispatch
>  10.74      0.96      0.23  call-with-output-string
>   7.44      0.20      0.16  #<procedure b042600 at ice-9/r4rs.scm:236:3 (p)>
> [...]


hi Ludo!
I recall something about tilde-displatch since you mentioned it.
A guy discussed the efficiency of format with me years ago, I talked
with Andy, but then I forgot it:

--------------------code-------------------
scheme@(guile-user)> ,profile (let lp ((i 10000)) (if (> i 0) (begin
(format #f "0x~2'0x, 0x~2'0x, 0x~2'0x" i i i) (lp (1- i)))))
%     cumulative   self             
time   seconds     seconds      name
22.58      0.56      0.23  tilde-dispatch
12.90      1.00      0.13  format
12.90      0.13      0.13  number->string
  8.06      0.13      0.08  format:out-char
  4.84      0.80      0.05  format:format-work
--------------------end------------------- 

In this case, we tried "0x~2'0x" and it's so slow that we can't bare it.
i=10000 is fast, but we need (* 600 80000)
And we found that "tilde-dispatch" cost too much. Is there any possible
to optimize it? 

> Sample count: 121
> Total time: 2.183744831 seconds (0.77482795 seconds in GC)
> --8<---------------cut here---------------end--------------->8---
> 
> Procedure #4 is ‘with-output-to-string’, so we can easily improve that
> by using ‘call-with-output-string’ directly instead:
> 
> --8<---------------cut here---------------start------------->8---
> scheme@(guile-user)> ,pr (with-output-to-port (%make-void-port "w") (lambda () (let loop ((i 40000)) (or (zero? i) (begin (format #t "~a ~a~%" 'foo 'bar) (loop (1- i)))))))
> %     cumulative   self             
> time   seconds     seconds      name
>  17.39      0.56      0.28  call-with-output-string
>  14.13      0.24      0.23  #<procedure 11e5a1a0 at /home/ludo/src/guile/module/ice-9/format.scm:782:46 (p)>
>  13.04      1.58      0.21  format
>   9.78      1.27      0.16  format:format-work
> [...]
> Sample count: 92
> Total time: 1.597127172 seconds (0.513423265 seconds in GC)
> --8<---------------cut here---------------end--------------->8---
> 
> Commit 6c9220064d987deee813cfd933d50353d14d4c0f.
> 
> To be continued...
> 
> Ludo’.