pserver causes slow serialization

[Graeme . Vetterlein]

First I'm forced to use outlook .. so profuse apologies before I even start
:-)

One of 'my users :-)' has complained that cvs commits from his emacs session
are very slow.
We use 'pserver' to access the repository. I use emacs locally and have not
noticed this behaviour, time
to investigate:

We have lines like:

^com/ntl ( date; cat ; ($CVSROOT/bin/tedcheckin com/ntl %{s V v})&)
>> $CVSROOT/CVSROOT/updatelog 2>&1

in loginfo. This causes the script 'tedcheckin' to run whenever a file is
checked in (it does a rebuild)
since I don't want to rebuild files one at a time as each is checked-in I
have some script magic in the 
background that waits around for 30 seconds to see if there is anything else
coming and batched it up.

Now I'm pretty careful to ensure I don't cause the various cvs command to
simply wait for me to finish, but
none the less if 'my user' checks in 3 files, they go in at a rate of one
every 30 seconds. Now the 
important parts of tedchekin are (at end):


        echo "About to do lastman cmd `date`"
        nohup lastman ${SOURCE}/${module}/.touch 30 "dobuild ${module}" <
/dev/null &
        echo "Done lastman cmd `date`"

        exit 0



At which point I'm expecting the pserver to exit and the client can do the
next commit. But NO the
client waits the 30 seconds that 'lastman' takes to run before the pserver
exits. Looking at the source
I'm thinking that the parent part of the cvs-pserver is not wait(2)ing for
it's child until it see the
pipes closed. To that end I've done various thing with redirecting
stdin/stdout/stderr to no avail. lastman starts:


        exec >> /tmp/$$.log 2>&1

Tracing via ps(1) we get:

$ date ; ps -fu priorc
Wednesday February 14 15:58:01 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD

# All quiet ...

$ date ; ps -fu priorc
Wednesday February 14 15:58:02 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3784     1  0 15:58:02 ?        0:00 sh -c ( date; cat ;
(/users/cvsroot/bin/tedcheckin com/ntl 'com/ntl/toys/htmlut
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3785  3784  0 15:58:02 ?        0:00 sleep 2
  priorc  3775  3774  0                   0:00 <defunct>

# Sometimes that defunct shows as "cvs --allow .."  Why don't 3774 clean up
his dead child? Waiting on IO?

$ date ; ps -fu priorc
Wednesday February 14 15:58:04 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3784     1  0 15:58:02 ?        0:00 sh -c ( date; cat ;
(/users/cvsroot/bin/tedcheckin com/ntl 'com/ntl/toys/htmlut
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3785  3784  0 15:58:02 ?        0:00 sleep 2
  priorc  3775  3774  0                   0:00 <defunct>

# 2 seconds nearly up ...

$ date ; ps -fu priorc
Wednesday February 14 15:58:05 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3784     1  0 15:58:02 ?        0:00 sh -c ( date; cat ;
(/users/cvsroot/bin/tedcheckin com/ntl 'com/ntl/toys/htmlut
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3775  3774  0                   0:00 <defunct>

# ...

$ date ; ps -fu priorc
Wednesday February 14 15:58:06 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3803  3797  0 15:58:05 ?        0:00 sleep 30
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3797     1  0 15:58:05 ?        0:00 /bin/ksh
/users/cvsroot/bin/lastman /users/projects/src/com/ntl/.touch 30 dobui
  priorc  3775  3774  0                   0:00 <defunct>

# OK lastman is running (and asleep) we must have closed stdout and stderr,
stdin was closed already.

$ date ; ps -fu priorc
Wednesday February 14 15:58:08 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3803  3797  0 15:58:05 ?        0:00 sleep 30
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3797     1  0 15:58:05 ?        0:00 /bin/ksh
/users/cvsroot/bin/lastman /users/projects/src/com/ntl/.touch 30 dobui
  priorc  3775  3774  0                   0:00 <defunct>

# So 3774 ... what are you waiting for? Your (direct) children are dead, the
0,1 and 2 are closed. reap that dead
child and die yourself!

$ date ; ps -fu priorc
Wednesday February 14 15:58:11 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3803  3797  0 15:58:05 ?        0:00 sleep 30
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3797     1  0 15:58:05 ?        0:00 /bin/ksh
/users/cvsroot/bin/lastman /users/projects/src/com/ntl/.touch 30 dobui
  priorc  3775  3774  0                   0:00 <defunct>

# ...I'm guessing there is another open FD here? Would I be right?

$ date ; ps -fu priorc
Wednesday February 14 15:58:21 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD
  priorc  3803  3797  0 15:58:05 ?        0:00 sleep 30
  priorc  3774   184  0 15:58:01 ?        0:00 cvs
--allow-root=/users/cvsroot pserver
  priorc  3797     1  0 15:58:05 ?        0:00 /bin/ksh
/users/cvsroot/bin/lastman /users/projects/src/com/ntl/.touch 30 dobui
  priorc  3775  3774  0                   0:00 <defunct>

# ...

$ date ; ps -fu priorc
Wednesday February 14 15:58:39 GMT 2001
     UID   PID  PPID  C    STIME TTY      TIME CMD

# Ah! time is up?! So the tidy up of lastman was enough to free things up.
His IO was closed, his parent was dead. The
only tidy up I can think affects this would be other open FD.


--

Graeme