run-shell-command timing

[smh@Franz.COM (Steve Haflich)]

   From: fritzson@PRC.Unisys.COM
   Date: Fri, 8 Sep 89 15:09:29 -0400

   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. 
   ...
      (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.
   ...

   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 have a partial analysis of this problem.  Before committing to a
complete analysis, I'll need to know on what platform you are running,
the version of its OS, and which version of Allegro.  Also, I'm
betting that multiprocessing is running, i.e., the lisp scheduler has
been started.  Right?

The problem has something to do with reading from a "slow" stream
under multiprocessing.  Normally, an input handler function associated
with an Allegro stream perform input by executing a Unix READ(II).
READ blocks on slow (asynchronous) streams like pipes and ttys when no
input is available.  Under multiprocessing, the input handler for slow
strams is replaced by one that does a LISTEN of the file descriptor,
and if no input is available it does a PROCESS-WAIT with LISTEN as the
WAIT-FUNCTION.  This prevents a process waiting for input from
blocking the entire lisp world.  (This is an outline -- there are
other important details not relevant here.)

Unfortunately, The "slow" stream returned by RUN-SHELL-COMMAND under
multiprocessing does not have the multiprocessing input handler, but
uses the blocking non-multiuprocessing version of the handler.  This
causes the entire lisp world to block reading from such a stream
whenever no characters are available.  We should probably fix the
internals of RUN-SHELL-COMMAND so that it uses the correct handler
under multiprocessing.

Unfortunately, while this might explain poor performance of other lisp
processes, it doesn't explain why so much system time appears in your
runs.  Although we don't run yp locally, I've tried other equivalent
tests here and don't see the same results.  This is why I want more
info about your OS and Allegro versions, your platform, and anything
else relevant about other lisp processes that might be running, etc.