On 2003-11-03 13:42:35 Luke Driscoll wrote:
>On a kernel 2.6.0-test9 as an NFS client I am having trouble
>transferring data to and from NFS servers. It it extraordinarily
>slow.??I?receive?the following information in dmesg:
>
>nfs warning: mount version older than kernel
>nfs: server safe not responding, still trying
You and me the same. Here's a message I sent to
[email protected] this Friday:
--quote--
xSubject: 2.6.0-test3-bk10-final regression getting out of hand
xDate: Fri, 31 Oct 2003 21:48:51 +0100
As reported in:
http://marc.theaimsgroup.com/?l=linux-kernel&m=106195494828814&w=2
I'm experiencing a serious NFS regression since 2.6.0-test3-bk10-final
(bk-set determined now). Since that, along the road to 2.6.0-test9,
something has gotten completely out of hand.
cp -a /mnt/oden/etc .
_2.6.0-test3-bk10_
2 minutes
_2.6.0-test3-bk10-final_
3 minutes 47 seconds
_2.6.0-test9_
29 minutes 54 seconds
Nothing has changed in hardware or setup, and the cp tests were done
today. Not being a programmer I tried to delete individual patches in
the bk-set, but couldn't find the exact breakage point.
Erasing changes to:
linux-2.6.0-test3-bk10/fs/nfs/dir.c
No change.
Erasing changes to:
linux-2.6.0-test3-bk10/fs/nfs/nfsroot.c
No change.
Erasing changes to:
linux-2.6.0-test3-bk10/include/linux/sunrpc/timer.h
linux-2.6.0-test3-bk10/net/sunrpc/timer.c
No change.
Erasing changes to:
linux-2.6.0-test3-bk10/net/sunrpc/clnt.c
Doesn't compile.
Erasing changes to:
linux-2.6.0-test3-bk10/include/linux/sunrpc/xprt.h
linux-2.6.0-test3-bk10/net/sunrpc/xprt.c
Doesn't compile.
Using TCP or DIRECTIO in -test9 makes no difference. Here's the
relevant .config-section:
#
# Network File Systems
#
CONFIG_NFS_FS=y
CONFIG_NFS_V3=y
# CONFIG_NFS_V4 is not set
# CONFIG_NFS_DIRECTIO is not set
CONFIG_NFSD=y
CONFIG_NFSD_V3=y
# CONFIG_NFSD_V4 is not set
# CONFIG_NFSD_TCP is not set
CONFIG_LOCKD=y
CONFIG_LOCKD_V4=y
CONFIG_EXPORTFS=y
CONFIG_SUNRPC=y
# CONFIG_SUNRPC_GSS is not set
# CONFIG_SMB_FS is not set
# CONFIG_CIFS is not set
# CONFIG_NCP_FS is not set
# CONFIG_CODA_FS is not set
# CONFIG_INTERMEZZO_FS is not set
# CONFIG_AFS_FS is not set
--unquote--
Mvh
Mats Johannesson
>>>>> " " == lista2 <Voluspa> writes:
> Using TCP or DIRECTIO in -test9 makes no difference. Here's the
> relevant .config-section:
So where *does* the big jump from 3 minutes to 29 minutes occur? Are
those numbers on TCP or are they UDP only?
What NIC are you using? From the error logs you showed us, it looked
like it might be a de4x5 driver. Have you tried using the tulip
driver?
Are you using ACPI to set up the hardware? If so, does turning it off
make a difference.
Does 'netstat -s' offer any other hints?
Cheers,
Trond
First, pardon for the silly typo : that changed the subject.
On 03 Nov 2003 11:09:54 -0500
Trond Myklebust wrote:
> >>>>> " " == lista2 <Voluspa> writes:
>
> > Using TCP or DIRECTIO in -test9 makes no difference. Here's the
> > relevant .config-section:
>
> So where *does* the big jump from 3 minutes to 29 minutes occur? Are
Not a clue. Gave up on NFS when nothing had changed in -test4 and -test5
(the first regression). This weekend I spent compiling to find the
'readahead' values. Am on a PII 400, so takes time to nail specifics.
Can't do another marathon compile until next weekend.
> those numbers on TCP or are they UDP only?
Am rather clueless when it comes to networking. You have to deduce from
the following. Remote is a Pentium 120 with Slackware 7.1.0 (Universal
NFS Server 2.2beta47) kernel 2.2.16. Does it even speak TCP? I compiled
this -test9 with TCP only when I saw the 29 minutes - and no change
afterwards. Looks like I'm using UDP, or?
> What NIC are you using? From the error logs you showed us, it looked
> like it might be a de4x5 driver. Have you tried using the tulip
> driver?
On this -test9 it is an integrated NIC which needs the de4x5 (Compaq
Presario 5640). When trying out Slackware 9.something it was
autodetected as a tulip but didn't work with that driver. The P120 uses
an ISA card driven by a cs89x0 module.
> Are you using ACPI to set up the hardware? If so, does turning it off
> make a difference.
Kernels are compiled without everything in that area. Not even the older
power management is compiled in.
> Does 'netstat -s' offer any other hints?
As I said, clueless about networking. So I'll have to use the weekend
for more info-gathering.
Mvh
Mats Johannesson
OBS
OBS Remove "wormprotection-" from the address. SWEN is killing me OBS
OBS
On 03 Nov 2003 11:09:54 -0500
Trond Myklebust wrote:
> >>>>> " " == lista2 <Voluspa> writes:
[...]
> So where *does* the big jump from 3 minutes to 29 minutes occur?
Copy test times:
2.6.0-test3-bk10 = ~ 2 minutes
2.6.0-test3-bk10-final -- 2.6.0-test6-bk9 = ~ 4 minutes
2.6.0-test6-bk10 -- 2.6.0-test9 = ~ 30 minutes (and more)
Here's "time", "nfsstat" and "netstat -s" from the relevant kernels. I
had shut down any excessive netservices and ran without X.
===Begin 2.6.0-test3-bk10===
# /bin/mount -t nfs oden.fish.net:/ /mnt/oden
# time cp -a /mnt/oden/etc .
real 2m3.153s
user 0m0.011s
sys 0m0.099s
# nfsstat
Server rpc stats:
calls badcalls badauth badclnt xdrcall
1 0 0 0 0
Server nfs v2:
null getattr setattr root lookup readlink
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
read wrcache write create remove rename
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
Server nfs v3:
null getattr setattr lookup access readlink
1 100% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%
Client rpc stats:
calls retrans authrefrsh
959 636 0
Client nfs v2:
null getattr setattr root lookup readlink
0 0% 236 24% 0 0% 0 0% 236 24% 5 0%
read wrcache write create remove rename
464 48% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 17 1% 1 0%
Client nfs v3:
null getattr setattr lookup access readlink
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%
# netstat -s
Ip:
6235 total packets received
0 forwarded
0 incoming packets discarded
1024 incoming packets delivered
1662 requests sent out
58 fragments dropped after timeout
3288 reassemblies required
332 packets reassembled ok
620 packet reassembles failed
Icmp:
0 ICMP messages received
0 input ICMP message failed.
ICMP input histogram:
1 ICMP messages sent
0 ICMP messages failed
ICMP output histogram:
time exceeded: 1
Tcp:
1 active connections openings
0 passive connection openings
0 failed connection attempts
0 connection resets received
0 connections established
5 segments received
6 segments send out
0 segments retransmited
0 bad segments received.
0 resets sent
Udp:
1019 packets received
0 packets to unknown port received.
0 packet receive errors
1655 packets sent
TcpExt:
ArpFilter: 0
1 TCP sockets finished time wait in fast timer
1 packets header predicted
TCPPureAcks: 1
TCPHPAcks: 1
TCPRenoRecovery: 0
TCPSackRecovery: 0
TCPSACKReneging: 0
TCPFACKReorder: 0
TCPSACKReorder: 0
TCPRenoReorder: 0
TCPTSReorder: 0
TCPFullUndo: 0
TCPPartialUndo: 0
TCPDSACKUndo: 0
TCPLossUndo: 0
TCPLoss: 0
TCPLostRetransmit: 0
TCPRenoFailures: 0
TCPSackFailures: 0
TCPLossFailures: 0
TCPFastRetrans: 0
TCPForwardRetrans: 0
TCPSlowStartRetrans: 0
TCPTimeouts: 0
TCPRenoRecoveryFail: 0
TCPSackRecoveryFail: 0
TCPSchedulerFailed: 0
TCPRcvCollapsed: 0
TCPDSACKOldSent: 0
TCPDSACKOfoSent: 0
TCPDSACKRecv: 0
TCPDSACKOfoRecv: 0
TCPAbortOnSyn: 0
TCPAbortOnData: 0
TCPAbortOnClose: 0
TCPAbortOnMemory: 0
TCPAbortOnTimeout: 0
TCPAbortOnLinger: 0
TCPAbortFailed: 0
TCPMemoryPressures: 0
===End 2.6.0-test3-bk10===
===Begin 2.6.0-test6-bk9===
# /bin/mount -t nfs oden.fish.net:/ /mnt/oden
# time cp -a /mnt/oden/etc .
real 3m43.904s
user 0m0.011s
sys 0m0.114s
# nfsstat
Server rpc stats:
calls badcalls badauth badclnt xdrcall
1 0 0 0 0
Server nfs v2:
null getattr setattr root lookup readlink
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
read wrcache write create remove rename
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
Server nfs v3:
null getattr setattr lookup access readlink
1 100% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%
Client rpc stats:
calls retrans authrefrsh
959 613 0
Client nfs v2:
null getattr setattr root lookup readlink
0 0% 236 24% 0 0% 0 0% 236 24% 5 0%
read wrcache write create remove rename
464 48% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 17 1% 1 0%
Client nfs v3:
null getattr setattr lookup access readlink
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%
# netstat -s
Ip:
6107 total packets received
0 forwarded
0 incoming packets discarded
1024 incoming packets delivered
1638 requests sent out
87 fragments dropped after timeout
3051 reassemblies required
332 packets reassembled ok
587 packet reassembles failed
Icmp:
0 ICMP messages received
0 input ICMP message failed.
ICMP input histogram:
0 ICMP messages sent
0 ICMP messages failed
ICMP output histogram:
Tcp:
1 active connections openings
0 passive connection openings
0 failed connection attempts
0 connection resets received
0 connections established
5 segments received
6 segments send out
0 segments retransmited
0 bad segments received.
0 resets sent
Udp:
1019 packets received
0 packets to unknown port received.
0 packet receive errors
1632 packets sent
TcpExt:
ArpFilter: 0
1 TCP sockets finished time wait in fast timer
1 packets header predicted
TCPPureAcks: 1
TCPHPAcks: 1
TCPRenoRecovery: 0
TCPSackRecovery: 0
TCPSACKReneging: 0
TCPFACKReorder: 0
TCPSACKReorder: 0
TCPRenoReorder: 0
TCPTSReorder: 0
TCPFullUndo: 0
TCPPartialUndo: 0
TCPDSACKUndo: 0
TCPLossUndo: 0
TCPLoss: 0
TCPLostRetransmit: 0
TCPRenoFailures: 0
TCPSackFailures: 0
TCPLossFailures: 0
TCPFastRetrans: 0
TCPForwardRetrans: 0
TCPSlowStartRetrans: 0
TCPTimeouts: 0
TCPRenoRecoveryFail: 0
TCPSackRecoveryFail: 0
TCPSchedulerFailed: 0
TCPRcvCollapsed: 0
TCPDSACKOldSent: 0
TCPDSACKOfoSent: 0
TCPDSACKRecv: 0
TCPDSACKOfoRecv: 0
TCPAbortOnSyn: 0
TCPAbortOnData: 0
TCPAbortOnClose: 0
TCPAbortOnMemory: 0
TCPAbortOnTimeout: 0
TCPAbortOnLinger: 0
TCPAbortFailed: 0
TCPMemoryPressures: 0
===End 2.6.0-test6-bk9===
===Begin 2.6.0-test6-bk10===
# /bin/mount -t nfs oden.fish.net:/ /mnt/oden
# time cp -a /mnt/oden/etc .
real 34m37.280s
user 0m0.009s
sys 0m0.105s
# nfsstat
Server rpc stats:
calls badcalls badauth badclnt xdrcall
1 0 0 0 0
Server nfs v2:
null getattr setattr root lookup readlink
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
read wrcache write create remove rename
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
Server nfs v3:
null getattr setattr lookup access readlink
1 100% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%
Client rpc stats:
calls retrans authrefrsh
963 569 0
Client nfs v2:
null getattr setattr root lookup readlink
0 0% 240 24% 0 0% 0 0% 236 24% 5 0%
read wrcache write create remove rename
464 48% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 17 1% 1 0%
Client nfs v3:
null getattr setattr lookup access readlink
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%
# netstat -s
Ip:
5859 total packets received
0 forwarded
0 incoming packets discarded
1028 incoming packets delivered
1603 requests sent out
555 fragments dropped after timeout
2804 reassemblies required
332 packets reassembled ok
555 packet reassembles failed
Icmp:
0 ICMP messages received
0 input ICMP message failed.
ICMP input histogram:
5 ICMP messages sent
0 ICMP messages failed
ICMP output histogram:
time exceeded: 5
Tcp:
1 active connections openings
0 passive connection openings
0 failed connection attempts
0 connection resets received
0 connections established
5 segments received
6 segments send out
0 segments retransmited
0 bad segments received.
0 resets sent
Udp:
1023 packets received
0 packets to unknown port received.
0 packet receive errors
1592 packets sent
TcpExt:
ArpFilter: 0
1 TCP sockets finished time wait in fast timer
1 packets header predicted
TCPPureAcks: 1
TCPHPAcks: 1
TCPRenoRecovery: 0
TCPSackRecovery: 0
TCPSACKReneging: 0
TCPFACKReorder: 0
TCPSACKReorder: 0
TCPRenoReorder: 0
TCPTSReorder: 0
TCPFullUndo: 0
TCPPartialUndo: 0
TCPDSACKUndo: 0
TCPLossUndo: 0
TCPLoss: 0
TCPLostRetransmit: 0
TCPRenoFailures: 0
TCPSackFailures: 0
TCPLossFailures: 0
TCPFastRetrans: 0
TCPForwardRetrans: 0
TCPSlowStartRetrans: 0
TCPTimeouts: 0
TCPRenoRecoveryFail: 0
TCPSackRecoveryFail: 0
TCPSchedulerFailed: 0
TCPRcvCollapsed: 0
TCPDSACKOldSent: 0
TCPDSACKOfoSent: 0
TCPDSACKRecv: 0
TCPDSACKOfoRecv: 0
TCPAbortOnSyn: 0
TCPAbortOnData: 0
TCPAbortOnClose: 0
TCPAbortOnMemory: 0
TCPAbortOnTimeout: 0
TCPAbortOnLinger: 0
TCPAbortFailed: 0
TCPMemoryPressures: 0
===End 2.6.0-test6-bk10===
Mvh
Mats Johannesson
OK. That points squarely at the RTO timeout "inheritance" change.
There are 2 differences as it stands in 2.6.0 w.r.t. the 2.4.23-pre
code: the no upper limit, and the inheritance update algorithm.
Could you therefore try the following patch.
Cheers,
Trond
diff -u --recursive --new-file linux-2.6.0-test9/include/linux/sunrpc/timer.h linux/include/linux/sunrpc/timer.h
--- linux-2.6.0-test9/include/linux/sunrpc/timer.h 2003-11-07 21:03:45.000000000 -0500
+++ linux/include/linux/sunrpc/timer.h 2003-11-09 16:55:43.000000000 -0500
@@ -25,9 +25,18 @@
static inline void rpc_set_timeo(struct rpc_rtt *rt, int timer, int ntimeo)
{
+ int *t;
if (!timer)
return;
- rt->ntimeouts[timer-1] = ntimeo;
+ t = &rt->ntimeouts[timer-1];
+ if (ntimeo < *t) {
+ if (*t > 0)
+ (*t)--;
+ } else {
+ if (ntimeo > 8)
+ ntimeo = 8;
+ *t = ntimeo;
+ }
}
static inline int rpc_ntimeo(struct rpc_rtt *rt, int timer)
diff -u --recursive --new-file linux-2.6.0-test9/net/sunrpc/timer.c linux/net/sunrpc/timer.c
--- linux-2.6.0-test9/net/sunrpc/timer.c 2003-11-07 21:06:11.000000000 -0500
+++ linux/net/sunrpc/timer.c 2003-11-09 16:57:15.000000000 -0500
@@ -40,6 +40,7 @@
rt->srtt[i] = init;
rt->sdrtt[i] = RPC_RTO_INIT;
}
+ memset(rt->ntimeouts, 0, sizeof(rt->ntimeouts));
}
/*