slow writes on nfs with bge devices

Mon Jan 22 07:44:24 UTC 2007

On Mon, 22 Jan 2007, Bruce Evans wrote:

> On Sun, 21 Jan 2007, Max Laier wrote:
>
>> On Sunday 21 January 2007 13:25, Bruce Evans wrote:

>> Can you just try to disable the delayed checksums via "ifconfig -txcsum"?
>> Should be an easy enough test.
>
> I haven't looked closely at the bge checksum code, but tried turning off
> checksums (various combinations) yesterday.  THis made no difference.

(An old version of) tcpdump -vv reported bad checksums if hardware
checksumming is on, but I assume that is because it can't see the
hardware checksums.

>>> tcpdump shows a lot of intervals between nfs write requests of almost
>>> exactly 10 mS (even with HZ = 1000, but more obvious with HZ = 100)
>>> for the broken case, so the problem is apparently related to timeouts,

Driver-level timestamps make this even more obious.

>> See above, I really think that there is something about that if_start loop
>> that might be causing this.
>
> I have some local changes in this area (much larger ifq length and
> watermark stuff to reduce tx interrupts).  I think they make no
> difference, but will have to test an unchanged driver more carefully.
> I assume that the if_start loop always calls the interface if_start
> if there is something in the ifq and the interface is not marked as
> active.

Tested again with almost pure RELENG_6.  There was little difference.

Here is some tcpdump output in case you can see the pattern better
than me.  Testing dd if=/dev/zero of=zz bs=1m count=100:

% 16:41:12.410346 IP phiplex.bde.org.1735978418 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x0
% 16:41:12.410349 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410350 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410350 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410351 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410352 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410379 IP phiplex.bde.org.1735978419 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x2000
% 16:41:12.410380 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410381 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410381 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410382 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.410383 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411318 IP besplex.bde.org.nfs > phiplex.bde.org.1735978418: reply ok 160 write [|nfs]

This is normal for writing a 16K fs-block.  Everything completes in < 1 mS.

% 16:41:12.411368 IP phiplex.bde.org.1735978438 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x28000

And the next block is started not more than about 50 uS later.  I don't
know why the next block is out of order.  Possibly related to it being
near the first indirect block.

% 16:41:12.411369 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411369 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411370 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411371 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411372 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411941 IP besplex.bde.org.nfs > phiplex.bde.org.1735978419: reply ok 160 write [|nfs]
% 16:41:12.411965 IP phiplex.bde.org.1735978439 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x2a000
% 16:41:12.411966 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411967 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411968 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411969 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.411970 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.412627 IP besplex.bde.org.nfs > phiplex.bde.org.1735978438: reply ok 160 write [|nfs]

% ...

Things go at full speed with sequential blocks to 0x34000 until here.
Then another sequential block:

16:41:12.416820 IP phiplex.bde.org.1735978446 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x38000
% 16:41:12.416821 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.416822 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.416823 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.416823 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.416824 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417486 IP besplex.bde.org.nfs > phiplex.bde.org.1735978445: reply ok 160 write [|nfs]
% 16:41:12.417506 IP phiplex.bde.org.1735978447 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x3a000
% 16:41:12.417507 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417508 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417509 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417509 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417510 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417881 IP phiplex.bde.org.1735978420 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x4000

But before the reply for 0x38000, it got back to sending the second 16K-block.
Still no speed problems.

% 16:41:12.417882 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417882 IP phiplex.bde.org > besplex.bde.org: udp

% 16:41:12.416820 IP phiplex.bde.org.1735978446 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x38000
% 16:41:12.417883 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417884 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.417885 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.418187 IP besplex.bde.org.nfs > phiplex.bde.org.1735978446: reply ok 160 write [|nfs]
% 16:41:12.418209 IP phiplex.bde.org.1735978448 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x3c000
% 16:41:12.418210 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.418211 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.418211 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.418212 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.418213 IP phiplex.bde.org > besplex.bde.org: udp

Stalled here.  Stalls seem to be related to out of order delivery.

% 16:41:12.492327 IP besplex.bde.org.822 > phiplex.bde.org.login: . ack 151 win 33304 <nop,nop,timestamp 18270197 1495076486>
% 16:41:12.667862 IP phiplex.bde.org.1735978447 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x3a000

Now it's retrying 0x3a000.

% 16:41:12.667863 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.667864 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.667864 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.667865 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.667866 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.668731 IP besplex.bde.org.nfs > phiplex.bde.org.1735978447: reply ok 160 write [|nfs]
% 16:41:12.668754 IP phiplex.bde.org.1735978449 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x3e000
% 16:41:12.668755 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.668755 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.668756 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.668757 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.668758 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.669650 IP besplex.bde.org.nfs > phiplex.bde.org.1735978449: reply ok 160 write [|nfs]

% ...

Then it got to here with only relatively minor glitches:

% 16:41:12.947085 IP phiplex.bde.org.1735978781 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x2d6000
% 16:41:12.947086 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947087 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947088 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947089 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947090 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947861 IP phiplex.bde.org.1735978421 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x6000

It's having problems writing 0x6000.  This is a retry.  Just for unreported
packet loss?  Perhaps my switch or cable is the problem.

% 16:41:12.947862 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947862 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947863 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947864 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947865 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.947956 IP besplex.bde.org.nfs > phiplex.bde.org.1735978781: reply ok 160 write [|nfs]
% 16:41:12.948739 IP besplex.bde.org.nfs > phiplex.bde.org.1735978421: reply ok 160 write [|nfs]

Now it has reached a state in which it ony tries to send 1 packet ever 10 mS.
10 mS is nfsclient's default tick interval.

% 16:41:12.957853 IP phiplex.bde.org.1735978422 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x8000
% 16:41:12.957854 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.957855 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.957856 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.957857 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.957857 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.958723 IP besplex.bde.org.nfs > phiplex.bde.org.1735978422: reply ok 160 write [|nfs]
% 16:41:12.967851 IP phiplex.bde.org.1735978424 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0xc000
% 16:41:12.967852 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.967853 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.967854 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.967854 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.967855 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.968802 IP besplex.bde.org.nfs > phiplex.bde.org.1735978424: reply ok 160 write [|nfs]

In fact, it is (re?)trying most of the old blocks that were out of
order after the first block.  It's not even sending one fs-block per 10 mS,
only one nfs-block = half of an fs-block.

% 16:41:12.977862 IP phiplex.bde.org.1735978425 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0xe000
% 16:41:12.977863 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.977864 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.977864 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.977865 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.977866 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.978714 IP besplex.bde.org.nfs > phiplex.bde.org.1735978425: reply ok 160 write [|nfs]
% 16:41:12.987850 IP phiplex.bde.org.1735978511 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0xba000
% 16:41:12.987851 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.987852 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.987853 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.987854 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.987855 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.988724 IP besplex.bde.org.nfs > phiplex.bde.org.1735978511: reply ok 160 write [|nfs]

This is out of order but still spaced at 10 mS.

% 16:41:12.997848 IP phiplex.bde.org.1735978427 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x12000
% 16:41:12.997849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.997850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.997850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.997851 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.997852 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:12.998715 IP besplex.bde.org.nfs > phiplex.bde.org.1735978427: reply ok 160 write [|nfs]

Back to early blocks.

% 16:41:13.007849 IP phiplex.bde.org.1735978536 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0xec000
% 16:41:13.007850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.007851 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.007852 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.007853 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.007854 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.008722 IP besplex.bde.org.nfs > phiplex.bde.org.1735978536: reply ok 160 write [|nfs]
% 16:41:13.017847 IP phiplex.bde.org.1735978430 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x18000
% 16:41:13.017848 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.017849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.017850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.017851 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.017852 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.018715 IP besplex.bde.org.nfs > phiplex.bde.org.1735978430: reply ok 160 write [|nfs]
% 16:41:13.027846 IP phiplex.bde.org.1735978561 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x11e000
% 16:41:13.027847 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.027848 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.027849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.027850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.027850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.028723 IP besplex.bde.org.nfs > phiplex.bde.org.1735978561: reply ok 160 write [|nfs]
% 16:41:13.037846 IP phiplex.bde.org.1735978594 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x160000
% 16:41:13.037847 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.037848 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.037849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.037849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.037850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.038718 IP besplex.bde.org.nfs > phiplex.bde.org.1735978594: reply ok 160 write [|nfs]
% 16:41:13.047845 IP phiplex.bde.org.1735978432 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x1c000
% 16:41:13.047846 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.047846 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.047847 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.047848 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.047849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.048717 IP besplex.bde.org.nfs > phiplex.bde.org.1735978432: reply ok 160 write [|nfs]
% 16:41:13.067845 IP phiplex.bde.org.1735978434 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x20000
% 16:41:13.067846 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.067847 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.067848 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.067848 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.067849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.068712 IP besplex.bde.org.nfs > phiplex.bde.org.1735978434: reply ok 160 write [|nfs]

20 mS interval before above.

% 16:41:13.077847 IP phiplex.bde.org.1735978619 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x192000
% 16:41:13.077849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.077849 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.077850 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.077851 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.077852 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.078723 IP besplex.bde.org.nfs > phiplex.bde.org.1735978619: reply ok 160 write [|nfs]
% 16:41:13.097842 IP phiplex.bde.org.1735978666 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x1f0000
% 16:41:13.097843 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.097844 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.097844 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.097845 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.097846 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.098713 IP besplex.bde.org.nfs > phiplex.bde.org.1735978666: reply ok 160 write [|nfs]
% 16:41:13.107841 IP phiplex.bde.org.1735978436 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x24000
% 16:41:13.107842 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.107843 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.107844 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.107845 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.107846 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.108712 IP besplex.bde.org.nfs > phiplex.bde.org.1735978436: reply ok 160 write [|nfs]

Even more 20 mS intervals.

% 16:41:13.137840 IP phiplex.bde.org.1735978715 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x252000
% 16:41:13.137841 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.137842 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.137842 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.137843 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.137844 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.138712 IP besplex.bde.org.nfs > phiplex.bde.org.1735978715: reply ok 160 write [|nfs]

30 mS.

% 16:41:13.147839 IP phiplex.bde.org.1735978473 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x6e000
% 16:41:13.147840 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.147841 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.147842 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.147843 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.147843 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.148709 IP besplex.bde.org.nfs > phiplex.bde.org.1735978473: reply ok 160 write [|nfs]

10 mS.

% 16:41:13.177841 IP phiplex.bde.org.1735978763 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x2b2000
% 16:41:13.180371 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.180372 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.180372 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.180373 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.180374 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.181243 IP besplex.bde.org.nfs > phiplex.bde.org.1735978763: reply ok 160 write [|nfs]

30 mS.

% 16:41:13.181270 IP phiplex.bde.org.1735978800 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x2fc000
% 16:41:13.181271 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.181272 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.181273 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.181274 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.181274 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.182194 IP besplex.bde.org.nfs > phiplex.bde.org.1735978800: reply ok 160 write [|nfs]
% 16:41:13.182216 IP phiplex.bde.org.1735978801 > besplex.bde.org.nfs: 1472 write fh 1028,575312/94220 8192 bytes @ 0x2fe000
% 16:41:13.182217 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.182218 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.182219 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.182220 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.182221 IP phiplex.bde.org > besplex.bde.org: udp
% 16:41:13.183070 IP besplex.bde.org.nfs > phiplex.bde.org.1735978801: reply ok 160 write [|nfs]

Back to normal.

Is this just what happens when nfs/udp loses packets?  nfs/tcp may be better
only because it has better retry algorthms.

Bruce