run-shell-command timing

[fritzson@PRC.Unisys.COM]

I have been writing code which reads the output of Unix programs run
by run-shell-command. It appears that a program which is reading from
a pipe stream incurs substantial system overhead, but I don't know why. 

For example, I have a loop which reads the lines of /etc/passwd and
returns some parsed form of the file. Since our local system uses the
Sun yellow pages to distribute password data, I rely on ypcat to look
up the password file. The loop initially calls "user-info-stream" to
open a stream to the data. A simple way to define that function is

   (defun user-info-stream ()
     (excl:run-shell-command "ypcat passwd"
			     :output :stream
			     :wait ()))

This definition produces this timing profile for the loop:

   cpu time (non-gc) 8434 msec user, 15200 msec system
   cpu time (gc)     200 msec user, 0 msec system
   cpu time (total)  8634 msec user, 15200 msec system
   real time  31760 msec

Notice the > 15 seconds of system cpu time.

If I redefine user-info-stream as:

   (defun user-info-stream ()
     ;; Use a temporary file to hold the ypcat output
     (excl:run-shell-command "ypcat passwd > /tmp/foo")
     (open "/tmp/foo" :direction :input))

I get this performance:

   cpu time (non-gc) 6466 msec user, 150 msec system
   cpu time (gc)     0 msec user, 0 msec system
   cpu time (total)  6466 msec user, 150 msec system
   real time  10260 msec

This time only .15 seconds of system cpu time. A very substantial improvement.

----------
Is any of this overhead being incurred in Allegro Common Lisp through
small buffer sizes or something similar? Is there anything I can do
about it? Although for this example I can use the trick of dumping the
data to a temporary file, there are real cases where I can't do this.

I would appreciate any suggesstions.

Rich Fritzson				fritzson@prc.unisys.com	
Unisys - Paoli Research Center		(215) 648-7606