Massive speed degradation versus NFS, running Visual Source Safe

[David Collier-Brown -- Customer Engineering]

   Bonnie Hoseit has found a case where Samba takes 16 minutes 35
seconds with 2.2.3a, versus as litle as 40 seconds using Hummingbird
NFS.
   The applications that show this behavior are Virtual Source
Safe, JBuilder and possibly PowerBuilder 9.  The VSS case is
easily reproducable, by running a command-line command that
applies the equivalent of diff to changed files in the repository.

   Scanning 1540 files consuming 14.7mb takes the 16-minute
time, and trussing the app, reading the logs and snooping
the wire showed a very odd pattern of reads from Samba....


12:07:34, log starts
12:07:34 srowe closed file data/a/aaaaaaaa (numopen=3)
12:07:34 srowe opened file data/a/aaaaaaaa read=Yes write=No
12:07:35 srowe closed file data/a/aaaaaaaa (numopen=3)
12:07:35 srowe opened file data/a/aaaaaaaa read=Yes write=No
12:07:35 srowe opened file data/a/aaaaaaaa.a read=Yes write=No
12:07:35 srowe closed file data/a/aaaaaaaa.a (numopen=4)
12:07:35 srowe opened file data/a/aaaaaaaa.a read=Yes write=No
12:07:35 srowe closed file data/a/aaaaaaaa.a (numopen=4)
12:07:35 srowe opened file data/a/aaaaaaaa.a read=Yes write=No
12:07:35 srowe closed file data/a/aaaaaaaa.a (numopen=4)
12:07:35 srowe opened file data/a/aaaaaaaa.a read=Yes write=No
12:07:35 srowe closed file data/a/aaaaaaaa.a (numopen=4)
12:07:36 srowe closed file data/a/aaaaaaaa (numopen=3)

As far as I can see, data/a/aaaaaaaa and data/a/aaaaaaaa.a
needed to be opened exactly once...

This repeats with data/g/gaaaaaaa.

12:07:36 srowe opened file data/g/gaaaaaaa read=Yes write=No
12:07:36 srowe closed file data/g/gaaaaaaa (numopen=3)
12:07:36 srowe opened file data/g/gaaaaaaa read=Yes write=No
12:07:36 srowe closed file data/g/gaaaaaaa (numopen=3)
12:07:36 srowe opened file data/g/gaaaaaaa read=Yes write=No
12:07:36 srowe closed file data/g/gaaaaaaa (numopen=3)
12:07:36 srowe opened file data/g/gaaaaaaa read=Yes write=No
12:07:36 srowe opened file data/g/gaaaaaaa.a read=Yes write=No
12:07:36 srowe closed file data/g/gaaaaaaa.a (numopen=4)
12:07:36 srowe opened file data/g/gaaaaaaa.a read=Yes write=No
12:07:36 srowe closed file data/g/gaaaaaaa.a (numopen=4)
12:07:36 srowe opened file data/g/gaaaaaaa.a read=Yes write=No
12:07:37 srowe closed file data/g/gaaaaaaa.a (numopen=4)
12:07:37 srowe opened file data/g/gaaaaaaa.a read=Yes write=No
12:07:37 srowe closed file data/g/gaaaaaaa.a (numopen=4)
12:07:37 srowe closed file data/g/gaaaaaaa (numopen=3)

and then again and again, in a cycle
12:07:34 data/a/aaaaaaaa
12:07:35 data/a/aaaaaaaa.a
12:07:36 data/g/gaaaaaaa
12:07:36 data/g/gaaaaaaa.a
12:07:37 data/m/mykaaaaa
12:07:38 data/m/mykaaaaa.b
12:07:39 data/k/khuaaaaa
12:07:39 data/k/khuaaaaa.b
12:07:40 data/m/mvwaaaaa
12:07:41 data/m/mvwaaaaa.b
12:07:42 data/a/aaaaaaaa
12:07:43 data/a/aaaaaaaa.a
12:07:43 data/a/aaaaaaaa

and so , repeating until

12:08:31, data/g/gaaaaaaa
12:08:32, data/g/gaaaaaaa.a
12:08:32, data/m/mykaaaaa
12:08:33, data/m/mykaaaaa.b
12:08:34, data/k/khuaaaaa

for a total of 12:08:34 - 12:07:34 one minute for this diff
of 5 (or 10) files.

   Out of pure gut feel, before doing more analysis, this looks
like something is going wring with the reads, such that VSS
thinks it must retry insanely.  I'll drill down a bit, but
first of all,
1) has anyone seen VSS, JBuilder or PowerBuilder misbehave similarly?
2) is there a fix for anthing that might confuse a PC diff
    in a later release than 2.2.3a?

--dave
-- 
David Collier-Brown,       | Always do right. This will gratify
Sun Microsystems,          | some people and astonish the rest.
Toronto, Ontario,          |                      -- Mark Twain
(905) 415-2849 or x52849   | davecb at canada.sun.com