Subject: Re: bug#12033: format should be faster

From: [email-masked] (Ludovic Courtès)
Date: Mon, 20 Aug 2012 23:51:38 +0200

Hi,

Here’s slightly modified code:

--8<---------------cut here---------------start------------->8---
(use-modules (ice-9 time))

(define (d len)
  (let* ((ll ((@ (srfi srfi-1) iota) len 1)) (m (1- (/ len 2))))
    (time
     (with-output-to-port (%make-void-port "w")
       (lambda ()
        (let lp ((a (list-head ll (1+ m))) (b (list-tail ll (1+ m))) (n 1))
          (and (< n len)
               (for-each (lambda (x y)
                           (display x)(display " ")(display y)
                           (display " "))
                         a b)
               (newline)
               (lp (append (list 1 (car b)) (cdr a))
                   (append (cdr b) (list (list-ref a m)))
                   (1+ n)))))))))

(define (f len)
  (let* ((ll ((@ (srfi srfi-1) iota) len 1)) (m (1- (/ len 2))))
    (time
     (with-output-to-port (%make-void-port "w")
       (lambda ()
        (let lp ((a (list-head ll (1+ m))) (b (list-tail ll (1+ m))) (n 1))
          (and (< n len)
               (for-each (lambda (x y)
                           (simple-format #t "~a ~a~%" x y))
                         a b)
               (lp (append (list 1 (car b)) (cdr a))
                   (append (cdr b) (list (list-ref a m)))
                   (1+ n)))))))))
--8<---------------cut here---------------end--------------->8---

Here’s the difference I have:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> (f 4000)
clock utime stime cutime cstime gctime
 8.37  8.35  0.00   0.00   0.00   0.56
$9 = #f
scheme@(guile-user)> (d 4000)
clock utime stime cutime cstime gctime
 6.37  6.35  0.00   0.00   0.00   0.05
$10 = #f
--8<---------------cut here---------------end--------------->8---

So ‘simple-format’ is 30% slower than the series of ‘display’
etc. calls.

A profile from Callgrind shows that ~22% of the program with ‘f’ is
spent in ‘scm_c_substring’ and the allocations it entails.

Commit b908768a7ec79f78def344c464186a51f55b69e8 in stable-2.0 changes
the situation like this:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> (d 4000)
clock utime stime cutime cstime gctime
 6.46  6.45  0.00   0.00   0.00   0.08
$3 = #f
scheme@(guile-user)> (f 4000)
clock utime stime cutime cstime gctime
 5.47  5.44  0.01   0.00   0.00   0.25
$4 = #f
--8<---------------cut here---------------end--------------->8---

Now, ‘simple-format’ is 15% faster than ‘display’.  Hurray!  ;-)

So, I’m closing this bug.

Note that (ice-9 format) is an order of magnitude slower, though:

--8<---------------cut here---------------start------------->8---
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
--8<---------------cut here---------------end--------------->8---

Admittedly, this should be fixed, but that’s another story...

Thanks,
Ludo’.