Subject: bug#15368: HTTP client is slow [2.0.9]

From: Mark H Weaver <[email-masked]>
Date: Fri, 13 Sep 2013 12:07:01 -0400

Hi Ludovic,

[email-masked] (Ludovic Courtès) writes:

> I just noticed that our HTTP client is very slow.  Consider this:
>
> (use-modules (web client)
>              (rnrs io ports)
>              (rnrs bytevectors)
>              (srfi srfi-11)
>              (ice-9 format))
>
> (define %uri
>   "http://ftp.gnu.org/gnu/idutils/idutils-4.6.tar.xz")
>
> (with-fluids ((%default-port-encoding #f))
>   (let*-values (((start)
>                  (gettimeofday))
>                 ((p)
>                  (let ((s (open-socket-for-uri %uri)))
>                    (setvbuf s _IONBF)

Why are you using an unbuffered port?  On my system, changing this to
_IOFBF increases throughput from 326 KiB/s to 489.0 KiB/s.

Also, the fact that my throughput is so much higher than yours (on a
several-year-old computer) is interesting.  Obviously I have a faster
net connection (wget reports 1.19M/s), but the fact that Guile can
benefit so much from my faster connection suggests that the body is read
reasonably efficiently.  I guess the problem is added latency somewhere,
or perhaps inefficiency in the writing of the request or reading of the
response headers.

Note that using an unbuffered port means that all the reads of the
response headers will be done 1 byte at a time.

>                    s))
>                 ((r h)
>                  (http-get %uri
>                            #:port p
>                            #:streaming? #t
>                            #:decode-body? #f))
>                 ((d len)
>                  (let ((b (get-bytevector-all h)))
>                    (values b (bytevector-length b)))
>                  ;; (let ((b (make-bytevector (* 5 (expt 2 20)))))
>                  ;;   (values b
>                  ;;           (get-bytevector-n! h b 0 (bytevector-length b))))
>                  )
>                 ((end)
>                  (gettimeofday))
>                 ((throughput)
>                  (let ((duration (- (car end) (car start))))
>                    (/ (/ len 1024.) duration 1.0))))
>     (format #t "~5,1f KiB/s (total: ~5,1f KiB)~%"
>             throughput (/ len 1024.))))
>
> Here I get a throughput of ~60 KiB/s, vs. ~400 KiB/s for wget and curl.
>
> Looking at the strace output reveals no real difference: they all make
> one syscall for each chunk of 1410 bytes.
>
> ‘time’ reports that Guile spends 0.2 s. in user and 0.8 s. in system,
> both of which are an order of magnitude higher than wget/curl.

If they make essentially the same syscalls, then why would the system
time be an order of magnitude higher?  Something doesn't sound right
here.

    Regards,
      Mark