Unexpectedly low read/write performance of open-pipe

[Rob Browning]

While evaluating guile as a possibility to replace some python code,
assuming I'm not just doing something wrong, I noticed that open-pipe
appears to transfer data *much* more slowly than python when OPEN_BOTH is
specified as opposed to OPEN_READ:

  discarding dev-zero as file: 12500.00 mb/s
  discarding dev-zero via OPEN_READ: 4132.23 mb/s
  discarding dev-zero via OPEN_WRITE: 1.42 mb/s

For something similar to the original python code and roughly similar to
open-pipe OPEN_BOTH (see code below) I see:

  mb/s: 1713.26754296

In the end, what I'd need is an OPEN_BOTH (or equivalent) that could
support block-reads and ideally read-delimited operations
on the subproces output pipe at speeds much closer to python's.


Here's the trivial guile test program:

#!/usr/bin/env guile -s
!#

(use-modules
 ((ice-9 binary-ports) :select (get-bytevector-n! put-bytevector))
 ((ice-9 format) :select (format))
 ((ice-9 popen) :select (open-pipe open-pipe*))
 ((rnrs bytevectors) :select (bytevector-length make-bytevector)))

(define (cat-bytes src dest len)
  ;; Discard bytes if dest is #f
  (let* ((buf (make-bytevector 65536))
         (buf-len (bytevector-length buf)))
    (let loop ((remaining len))
      (unless (zero? remaining)
        (let ((n-or-eof (get-bytevector-n! src buf 0 (min remaining buf-len))))
          (unless (eof-object? n-or-eof)
            (when dest (put-bytevector dest buf 0 n-or-eof))
            (loop (- remaining n-or-eof))))))))

(define *discard* #f)

(define *dev-zero* (with-fluids ((%default-port-encoding #f))
                     (open-input-file "/dev/zero")))

(define (cat-zero mode)
  (with-fluids ((%default-port-encoding #f))
    (open-pipe* mode "cat" "/dev/zero")))

(define (time-cat-mb mb src dest)
  (let ((start (tms:clock (times))))
    (cat-bytes src dest (* mb 1024 1024))
    (when dest (force-output dest))
    (let ((end (tms:clock (times))))
      (format (current-error-port)
              "~,2f mb/s\n" (/ mb
                               (/ (- (tms:clock (times)) start)
                                  internal-time-units-per-second))))))

(display "discarding dev-zero as file: " (current-error-port))
(time-cat-mb 10000 *dev-zero* *discard*)
(display "discarding dev-zero via OPEN_READ: " (current-error-port))
(time-cat-mb 5000 (cat-zero OPEN_READ) *discard*)
(display "discarding dev-zero via OPEN_WRITE: " (current-error-port))
(time-cat-mb 10 (cat-zero OPEN_BOTH) *discard*)

And here's the python code:

#!/usr/bin/env python

import os, subprocess

proc = subprocess.Popen(['cat', '/dev/zero'],
                        stdin=subprocess.PIPE, stdout=subprocess.PIPE,
                        close_fds = True, bufsize = 4096)

n_kb = 1000000
start = os.times()[4]
written = 0
for i in range(n_kb):
    assert(len(proc.stdout.read(1024)) == 1024)
    written += 1024
end = os.times()[4]

proc.terminate()
proc.wait()

print "mb/s:", (n_kb / 1024.0) / (end - start)

Thanks
-- 
Rob Browning
rlb @defaultvalue.org and @debian.org
GPG as of 2011-07-10 E6A9 DA3C C9FD 1FF8 C676 D2C4 C0F0 39E9 ED1B 597A
GPG as of 2002-11-03 14DD 432F AE39 534D B592 F9A0 25C8 D377 8C7E 73A4