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

From: [email-masked] (Ludovic Courtès)
Date: Tue, 21 Aug 2012 00:37:35 +0200

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)>
[...]
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’.