Strange delays on NFS server

Strange delays on NFS server

[Ian Thurlbeck]

Dear All

I am getting strange delays on our NFS server. Everything will
be fine for maybe 5 to 10 minutes, then saving a small text file
from a client machine will suddenly take 15 seconds or more.
Similarly, mozilla will pause accessing a page for ages ~30secs
(I assume it's poking about in ~/.mozilla). Everything pops back to 
normal afterwards. NFS server is lightly used at the moment.

System is running Fedora Core1 (2188 kernel), 3ware 7500 raid, ext3.
I have 32 nfsd processes, running NFS V3/tcp, 8192 block size,
single duplex 100Mbit etherpro. Clients have similar OS/mount opts.

I noticed a possible link to this:

http://sourceforge.net/mailarchive/message.php?msg_id=9080621

Anyone care to comment?

On the NFS FAQ it suggests raising:

# echo 262144 > /proc/sys/net/core/rmem_default
# echo 262144 > /proc/sys/net/core/rmem_max

Mine are 65536 and 131071 respectively, but the FAQ gives
strong caveats about doing this.

Here is the stats off the server (I haven't rebooted since
I switched to V3):

root@dunnet ipv4]# nfsstat -s
Server rpc stats:
calls      badcalls   badauth    badclnt    xdrcall
1699297854   2          2          0          0
Server nfs v2:
null       getattr    setattr    root       lookup     readlink
907181  1% 19385896 29% 375501  0% 0       0% 5647809  8% 7246    0%
read       wrcache    write      create     remove     rename
24270181 37% 0       0% 13513519 20% 261062  0% 321986  0% 64110   0%
link       symlink    mkdir      rmdir      readdir    fsstat
119741  0% 2444    0% 1372    0% 2242    0% 125821  0% 45434   0%

Server nfs v3:
null       getattr    setattr    lookup     access     readlink
2894636  0% 61177594  3% 1701443  0% 15723650  0% 39582580  2% 47421   0%
read       write      create     mkdir      symlink    mknod
1428854462 87% 71166229  4% 763544  0% 4621    0% 18314   0% 0       0%
remove     rmdir      rename     link       readdir    readdirplus
602276  0% 1631    0% 326031  0% 169218  0% 115075  0% 698649  0%
fsstat     fsinfo     pathconf   commit
54385   0% 72137   0% 2       0% 10272411  0%

Any suggestions ?


Thanks

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Olaf Kirch]

On Wed, Aug 11, 2004 at 11:55:17AM +0100, Ian Thurlbeck wrote:
> System is running Fedora Core1 (2188 kernel), 3ware 7500 raid, ext3.
> I have 32 nfsd processes, running NFS V3/tcp, 8192 block size,
> single duplex 100Mbit etherpro. Clients have similar OS/mount opts.

Anyone more familiar with the Fedora kernel - does it happen
to have io barriers enabled by default?

Olaf
-- 
Olaf Kirch     |  The Hardware Gods hate me.
okir@suse.de   |
---------------+ 


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Steve Dickson]

Ian Thurlbeck wrote:

> I am getting strange delays on our NFS server. Everything will
> be fine for maybe 5 to 10 minutes, then saving a small text file
> from a client machine will suddenly take 15 seconds or more.
> Similarly, mozilla will pause accessing a page for ages ~30secs
> (I assume it's poking about in ~/.mozilla). Everything pops back to 
> normal afterwards. NFS server is lightly used at the moment.

Boy... it sure sounds to me like some type of daemon or something is 
starting up
that is bring the machine to its knees... . Would it be possible to have 
a top -i running
on the server when this pause occurs?

SteveD.


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Steve Dickson wrote:
> 
> 
> Ian Thurlbeck wrote:
> 
>> I am getting strange delays on our NFS server. Everything will
>> be fine for maybe 5 to 10 minutes, then saving a small text file
>> from a client machine will suddenly take 15 seconds or more.
>> Similarly, mozilla will pause accessing a page for ages ~30secs
>> (I assume it's poking about in ~/.mozilla). Everything pops back to 
>> normal afterwards. NFS server is lightly used at the moment.
> 
> 
> Boy... it sure sounds to me like some type of daemon or something is 
> starting up
> that is bring the machine to its knees... . Would it be possible to have 
> a top -i running
> on the server when this pause occurs?
> 
> SteveD.
> 

OK, I've been running "top -d 1 -i" and trying to see what comes up when
the server freezes. I caught one instance where a delay coincided
with about 15 nfsd + 1 kjournald process appearing in the top
display. I'm simultaneously looking at a graphical network tool to try
and see the traffic going to the server - anyone got a better suggestion?

Tomorrow I'll batch top to log to a file and get some users to
note the exact time of any delays (using the ntp-synced clocks) and
see if I can see any correlation.

I'll report back with any findings.

Many thanks

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Olaf Kirch]

On Wed, Aug 11, 2004 at 05:08:45PM +0100, Ian Thurlbeck wrote:
> OK, I've been running "top -d 1 -i" and trying to see what comes up when
> the server freezes. I caught one instance where a delay coincided
> with about 15 nfsd + 1 kjournald process appearing in the top
> display. I'm simultaneously looking at a graphical network tool to try
> and see the traffic going to the server - anyone got a better suggestion?

This sounds exactly like the COMMIT stall problem for which I submitted
the early-writeout patch to this list about a week ago.

I've been thinking about this a little more. It may be that one reason
the problem is more pronounced in in 2.6 than in 2.4 is the new io
barrier code. In 2.6 ext3 uses barriers by default; Suse's 2.6 has reiserfs
patches that add barriers (and enables them by default). We've reports of
this problem on both file systems.

JFS does i/o barriers while XFS does not; and this also fits the pattern
of what Ian reports. I dimly remember there's a kernel command line
option to turn off barriers at the block io level. Can you try if
that helps, Ian?

The more I think about this, the more I believe the early-writeout patch
is the right way to address this problem (short of turning off barriers).
When data hits the NFS server, it is supposed to go to disk rather
soonishly. This also covers most of the rewrite case, at least as long
as you have just one application writing to the file - all rewriting
happens in the client cache.

The crucial question is, what is a good heursitic to choose when to
initiate a write-out. Sequential writes to the end of file are easy
enough to detect.

I have a somewhat updated version of my patch that covers just this
case, and exports a sysctl to let you tune how often it initiates
an early write-out.

Olaf
-- 
Olaf Kirch     |  The Hardware Gods hate me.
okir@suse.de   |
---------------+ 


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Phy Prabab]

Is it possible to get the patch to test it out?  I am
having some issues that are similar and would like to
see if your patch helps.

Thanks!
Phy

--- Olaf Kirch <okir@suse.de> wrote:

> On Wed, Aug 11, 2004 at 05:08:45PM +0100, Ian
> Thurlbeck wrote:
> > OK, I've been running "top -d 1 -i" and trying to
> see what comes up when
> > the server freezes. I caught one instance where a
> delay coincided
> > with about 15 nfsd + 1 kjournald process appearing
> in the top
> > display. I'm simultaneously looking at a graphical
> network tool to try
> > and see the traffic going to the server - anyone
> got a better suggestion?
> 
> This sounds exactly like the COMMIT stall problem
> for which I submitted
> the early-writeout patch to this list about a week
> ago.
> 
> I've been thinking about this a little more. It may
> be that one reason
> the problem is more pronounced in in 2.6 than in 2.4
> is the new io
> barrier code. In 2.6 ext3 uses barriers by default;
> Suse's 2.6 has reiserfs
> patches that add barriers (and enables them by
> default). We've reports of
> this problem on both file systems.
> 
> JFS does i/o barriers while XFS does not; and this
> also fits the pattern
> of what Ian reports. I dimly remember there's a
> kernel command line
> option to turn off barriers at the block io level.
> Can you try if
> that helps, Ian?
> 
> The more I think about this, the more I believe the
> early-writeout patch
> is the right way to address this problem (short of
> turning off barriers).
> When data hits the NFS server, it is supposed to go
> to disk rather
> soonishly. This also covers most of the rewrite
> case, at least as long
> as you have just one application writing to the file
> - all rewriting
> happens in the client cache.
> 
> The crucial question is, what is a good heursitic to
> choose when to
> initiate a write-out. Sequential writes to the end
> of file are easy
> enough to detect.
> 
> I have a somewhat updated version of my patch that
> covers just this
> case, and exports a sysctl to let you tune how often
> it initiates
> an early write-out.
> 
> Olaf
> -- 
> Olaf Kirch     |  The Hardware Gods hate me.
> okir@suse.de   |
> ---------------+ 
> 
> 
>
-------------------------------------------------------
> SF.Net email is sponsored by Shop4tech.com-Lowest
> price on Blank Media
> 100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R
> for only $33
> Save 50% off Retail on Ink & Toner - Free Shipping
> and Free Gift.
>
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
> _______________________________________________
> NFS maillist  -  NFS@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/nfs
> 


__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com 


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Christoph Hellwig]

On Wed, Aug 11, 2004 at 06:41:35PM +0200, Olaf Kirch wrote:
> I've been thinking about this a little more. It may be that one reason
> the problem is more pronounced in in 2.6 than in 2.4 is the new io
> barrier code.

2.6 mainline doesn't have barrier support.



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Steve Dickson]

Ian Thurlbeck wrote:

> I'm simultaneously looking at a graphical network tool to try
> and see the traffic going to the server - anyone got a better suggestion?

Grab the latest xosview.... it show disk,cpu and nfs activity graphically...

SteveD.


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Norman Weathers]

This would be probably what I am experiencing as well.  Using XFS on our NFS 
server (2.6.7 kernel, Fedora Core 2), we get exceptional numbers.  Using JFS, 
it stalls to the point of being unusable.  Does anyone know the kenrnel 
command line option that Olaf is mentioning?

On Wednesday 11 August 2004 11:41, Olaf Kirch wrote:
> On Wed, Aug 11, 2004 at 05:08:45PM +0100, Ian Thurlbeck wrote:
> > OK, I've been running "top -d 1 -i" and trying to see what comes up when
> > the server freezes. I caught one instance where a delay coincided
> > with about 15 nfsd + 1 kjournald process appearing in the top
> > display. I'm simultaneously looking at a graphical network tool to try
> > and see the traffic going to the server - anyone got a better suggestion?
>
> This sounds exactly like the COMMIT stall problem for which I submitted
> the early-writeout patch to this list about a week ago.
>
> I've been thinking about this a little more. It may be that one reason
> the problem is more pronounced in in 2.6 than in 2.4 is the new io
> barrier code. In 2.6 ext3 uses barriers by default; Suse's 2.6 has reiserfs
> patches that add barriers (and enables them by default). We've reports of
> this problem on both file systems.
>
> JFS does i/o barriers while XFS does not; and this also fits the pattern
> of what Ian reports. I dimly remember there's a kernel command line
> option to turn off barriers at the block io level. Can you try if
> that helps, Ian?
>
> The more I think about this, the more I believe the early-writeout patch
> is the right way to address this problem (short of turning off barriers).
> When data hits the NFS server, it is supposed to go to disk rather
> soonishly. This also covers most of the rewrite case, at least as long
> as you have just one application writing to the file - all rewriting
> happens in the client cache.
>
> The crucial question is, what is a good heursitic to choose when to
> initiate a write-out. Sequential writes to the end of file are easy
> enough to detect.
>
> I have a somewhat updated version of my patch that covers just this
> case, and exports a sysctl to let you tune how often it initiates
> an early write-out.
>
> Olaf

-- 

Norman Weathers
SIP Linux Cluster
TCE UNIX
ConocoPhillips
Houston, TX

Office:  LO2003
Phone:   ETN  639-2727
	 or (281) 293-2727


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Olaf Kirch wrote:
> On Wed, Aug 11, 2004 at 05:08:45PM +0100, Ian Thurlbeck wrote:
> 
>>OK, I've been running "top -d 1 -i" and trying to see what comes up when
>>the server freezes. I caught one instance where a delay coincided
>>with about 15 nfsd + 1 kjournald process appearing in the top
>>display. I'm simultaneously looking at a graphical network tool to try
>>and see the traffic going to the server - anyone got a better suggestion?
> 
> 
> This sounds exactly like the COMMIT stall problem for which I submitted
> the early-writeout patch to this list about a week ago.
> 
> I've been thinking about this a little more. It may be that one reason
> the problem is more pronounced in in 2.6 than in 2.4 is the new io
> barrier code. In 2.6 ext3 uses barriers by default; Suse's 2.6 has reiserfs
> patches that add barriers (and enables them by default). We've reports of
> this problem on both file systems.

Olaf

I'm confused - you're talking about 2.6 but I'm running 2.4.22 (FC1). 
Does your analysis apply to both 2.4 and 2.6 kernels?

Subjectively, the problem seems to be getting worse the longer the 
server is running (uptime 80 days currently).  This could be a 
red-herring of course.

Ian

PS Red-herring = misleading or incorrect clue or idea!

> JFS does i/o barriers while XFS does not; and this also fits the pattern
> of what Ian reports. I dimly remember there's a kernel command line
> option to turn off barriers at the block io level. Can you try if
> that helps, Ian?
> 
> The more I think about this, the more I believe the early-writeout patch
> is the right way to address this problem (short of turning off barriers).
> When data hits the NFS server, it is supposed to go to disk rather
> soonishly. This also covers most of the rewrite case, at least as long
> as you have just one application writing to the file - all rewriting
> happens in the client cache.
> 
> The crucial question is, what is a good heursitic to choose when to
> initiate a write-out. Sequential writes to the end of file are easy
> enough to detect.
> 
> I have a somewhat updated version of my patch that covers just this
> case, and exports a sysctl to let you tune how often it initiates
> an early write-out.
> 
> Olaf


-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Olaf Kirch wrote:
> On Wed, Aug 11, 2004 at 05:08:45PM +0100, Ian Thurlbeck wrote:
> 
>>OK, I've been running "top -d 1 -i" and trying to see what comes up when
>>the server freezes. I caught one instance where a delay coincided
>>with about 15 nfsd + 1 kjournald process appearing in the top
>>display. I'm simultaneously looking at a graphical network tool to try
>>and see the traffic going to the server - anyone got a better suggestion?
> 
> 
> This sounds exactly like the COMMIT stall problem for which I submitted
> the early-writeout patch to this list about a week ago.
> 
> I've been thinking about this a little more. It may be that one reason
> the problem is more pronounced in in 2.6 than in 2.4 is the new io
> barrier code. In 2.6 ext3 uses barriers by default; Suse's 2.6 has reiserfs
> patches that add barriers (and enables them by default). We've reports of
> this problem on both file systems.
> 
> JFS does i/o barriers while XFS does not; and this also fits the pattern
> of what Ian reports. I dimly remember there's a kernel command line
> option to turn off barriers at the block io level. Can you try if
> that helps, Ian?
> 
> The more I think about this, the more I believe the early-writeout patch
> is the right way to address this problem (short of turning off barriers).
> When data hits the NFS server, it is supposed to go to disk rather
> soonishly. This also covers most of the rewrite case, at least as long
> as you have just one application writing to the file - all rewriting
> happens in the client cache.
> 
> The crucial question is, what is a good heursitic to choose when to
> initiate a write-out. Sequential writes to the end of file are easy
> enough to detect.
> 
> I have a somewhat updated version of my patch that covers just this
> case, and exports a sysctl to let you tune how often it initiates
> an early write-out.
> 
> Olaf

Dear All

I ran top in batch mode this afternoon, turned off imapd/smb services
for good measure, and noted the times of any delays.  I then checked
the top log file and they all coincide with something like this
turning up in the process list:

14:28:30  up 80 days,  5:25,  2 users,  load average: 0.42, 0.15, 0.12
118 processes: 116 sleeping, 1 running, 1 zombie, 0 stopped
CPU states:  cpu    user    nice  system    irq  softirq  iowait    idle
            total    0.0%    0.0%    0.9%   0.0%     0.0%    0.0%   99.0%
Mem:   514664k av,  380296k used,  134368k free,       0k shrd,   37464k 
buff
         66096k active,             231056k inactive
Swap: 1052216k av,   14712k used, 1037504k free       239788k cached

   PID USER  PRI  NI  SIZE  RSS SHARE STAT %CPU %MEM   TIME CPU COMMAND
  6365 root  16   0  1244 1244   880 R     0.9  0.2   0:15   0 top
   156 root  15   0     0    0     0 DW    0.0  0.0  25:45   0 kjournald


The kjournald process is quickly joined by a bunch of nfsd's:


14:28:34  up 80 days,  5:25,  2 users,  load average: 0.63, 0.20, 0.14
118 processes: 115 sleeping, 2 running, 1 zombie, 0 stopped
CPU states:  cpu    user    nice  system    irq  softirq  iowait    idle
            total   38.0%    0.0%   31.4%   0.0%     0.0%    0.0%   30.4%
Mem:   514664k av,  509240k used,    5424k free,       0k shrd,   29328k 
buff
         64028k active,             361036k inactive
Swap: 1052216k av,   14712k used, 1037504k free        375832k cached

   PID USER PRI  NI  SIZE  RSS SHARE STAT %CPU %MEM   TIME CPU COMMAND
  6365 root  16   0  1244 1244   880 R     0.9  0.2   0:15   0 top
   156 root  15   0     0    0     0 DW    0.0  0.0  25:45   0 kjournald
  2021 root  15   0     0    0     0 DW    0.0  0.0  17:38   0 nfsd
  2037 root  15   0     0    0     0 DW    0.0  0.0  17:51   0 nfsd
  2042 root  15   0     0    0     0 DW    0.0  0.0  17:07   0 nfsd
  2044 root  15   0     0    0     0 DW    0.0  0.0  16:44   0 nfsd

And then the bdflush process joins in and the number of nfsd processes
grows, then shrinks back, and finally they all disappear.

Full log is at:

http://www.stams.strath.ac.uk/~ian/nfs/

File top.log (2.8MB)

Events are around 14:29:10, 14:49:00, 14:47:50, and a belter at 15:11:05

Is there anything more useful I can do ??

Many thanks

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Steve Dickson]

Ian Thurlbeck wrote:

>   PID USER PRI  NI  SIZE  RSS SHARE STAT %CPU %MEM   TIME CPU COMMAND
>  6365 root  16   0  1244 1244   880 R     0.9  0.2   0:15   0 top
>   156 root  15   0     0    0     0 DW    0.0  0.0  25:45   0 kjournald
>  2021 root  15   0     0    0     0 DW    0.0  0.0  17:38   0 nfsd
>  2037 root  15   0     0    0     0 DW    0.0  0.0  17:51   0 nfsd
>  2042 root  15   0     0    0     0 DW    0.0  0.0  17:07   0 nfsd
>  2044 root  15   0     0    0     0 DW    0.0  0.0  16:44   0 nfsd
>
> And then the bdflush process joins in and the number of nfsd processes
> grows, then shrinks back, and finally they all disappear.
>
Hmm... this is kinda what I expected... nfsd is waiting on the local 
filesystem....
Would it be nice if nfsd would know how to speak aio...  but  back to 
reality.....
What happens if you double/triple (assuming you have enough memory)  the 
number nfsd
that are started? does it help or hurt? My guess is it probably will not 
make a difference
but you never know....

SteveD.


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Steve Dickson wrote:
> 
> 
> Ian Thurlbeck wrote:
> 
>>   PID USER PRI  NI  SIZE  RSS SHARE STAT %CPU %MEM   TIME CPU COMMAND
>>  6365 root  16   0  1244 1244   880 R     0.9  0.2   0:15   0 top
>>   156 root  15   0     0    0     0 DW    0.0  0.0  25:45   0 kjournald
>>  2021 root  15   0     0    0     0 DW    0.0  0.0  17:38   0 nfsd
>>  2037 root  15   0     0    0     0 DW    0.0  0.0  17:51   0 nfsd
>>  2042 root  15   0     0    0     0 DW    0.0  0.0  17:07   0 nfsd
>>  2044 root  15   0     0    0     0 DW    0.0  0.0  16:44   0 nfsd
>>
>> And then the bdflush process joins in and the number of nfsd processes
>> grows, then shrinks back, and finally they all disappear.
>>
> Hmm... this is kinda what I expected... nfsd is waiting on the local 
> filesystem....
> Would it be nice if nfsd would know how to speak aio...  but  back to 
> reality.....
> What happens if you double/triple (assuming you have enough memory)  the 
> number nfsd
> that are started? does it help or hurt? My guess is it probably will not 
> make a difference

I bumped the nfsd's up to 64 (from 32) and subjectively the problem gets 
worse.  I then reduced them to 16 and things are a bit better...

Would changing some of the bdflush settings help at all?

Thanks

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Dear Olaf, NFS list

Olaf sent me a patch to test:

--- fs/nfsd/vfs.c.orig  2003-06-13 16:51:37.000000000 +0200
+++ fs/nfsd/vfs.c       2004-08-16 16:52:53.000000000 +0200
@@ -760,6 +760,21 @@
                 }
                 last_ino = inode->i_ino;
                 last_dev = inode->i_dev;
+       } else if (err >= 0 && !stable) {
+               /* If we've been writing several pages, schedule them
+                * for the disk immediately. The client may be streaming
+                * and we don't want to hang on a huge journal sync when the
+                * commit comes in
+                */
+               struct address_space    *mapping;
+
+               /* This assumes a minimum page size of 1K, and will issue
+                * a filemap_flushfast call every 64 pages written by the
+                * client. */
+               if ((cnt & 4095) == 0
+                && ((offset >> 12) & 63) == 0
+                && (mapping = inode->i_mapping) != NULL)
+                       filemap_fdatasync(mapping);
         }

         dprintk("nfsd: write complete err=%d\n", err);



I have tested the patched kernel - it is no different. In fact
I'd say it's slightly worse.  I've been running "atop" to monitor
net/disk io and during an "event" I see that the main 3ware raid
array is writing at 100% (60MB/sec+) for up to 50 seconds.  There
is little network traffic. During this period client machines are
unusable if they are requesting stuff off the server.

What on earth could be writing up to 3GB of data to the drive ?
As before the usual suspects of kjournald, kupdated, bdflush and
nfsd turn up on the process list.

Just how big is the nfs write cache on a typical server ? Is it
writing the whole lot one go ?

Thanks for your efforts

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Jan Bruvoll]

Dear all,

Ian Thurlbeck wrote:

> I have tested the patched kernel - it is no different. In fact
> I'd say it's slightly worse.  I've been running "atop" to monitor
> net/disk io and during an "event" I see that the main 3ware raid
> array is writing at 100% (60MB/sec+) for up to 50 seconds.  There
> is little network traffic. During this period client machines are
> unusable if they are requesting stuff off the server.


I haven't had the opportunity to test things this thoroughly yet, but I 
see the same symptoms on our server here - when the "hick-up" comes, the 
server, if under heavy fire, will be completely unresponsive for as long 
as it is trying to get out of the mess. After a little while, things 
will clear up again (I guess that could have to do with clients just 
giving up on things), just to clog up about a minute later.

And as Ian mentions, the clients will be stuck for as long as this goes on.

Thanks very much for your continued efforts - if there is anything I 
could do to help debug this issue or otherwise contribute to the fixing 
of this problem, I'd happily oblige!

Best regards
Jan



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Neil Brown]

On Monday August 16, ian@stams.strath.ac.uk wrote:
> 
> I bumped the nfsd's up to 64 (from 32) and subjectively the problem gets 
> worse.  I then reduced them to 16 and things are a bit better...

Odd.

> 
> Would changing some of the bdflush settings help at all?

Maybe.  I would start with
  echo 200 > /proc/sys/vm/dirty_expire_centisecs

You said you are using ext3.  Are you using journal=data or the
default journal=ordered ??

Also, it would be interesting to compare nfs ops per second against
disk i/os per second over time.
Something like..

  while :
  do
    perl -ne 'if (/^proc3/)  { @a=split ; shift @a; shift @a; print eval(join("+", @a))."  ";}' /proc/net/rpc/nfsd
    perl -ne 'if (/hda /) { @a=split; print $a[9]."\n";}' /proc/diskstats  
    sleep 1
  done | perl -ne '@_=split; print( ($_[0]-$a[0])." ".($_[1]-$a[1])."\n"); @a=@_;'

If the pauses correspond to periods with very low nfs ops/sec and very
high writes per second, then it confirms that it is a disk flushing
problem.

It would also be interesting to see if there was a pattern in the
timing, particular how long the interval was between one pause and the
next.  
Also getting these sets of number for different numbers of nfsd
threads could turn your subjective impression into objective data.

NeilBrown


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Neil Brown wrote:
> On Monday August 16, ian@stams.strath.ac.uk wrote:
> 
>>I bumped the nfsd's up to 64 (from 32) and subjectively the problem gets 
>>worse.  I then reduced them to 16 and things are a bit better...
> 
> 
> Odd.
> 
>>Would changing some of the bdflush settings help at all?
> 
> 
> Maybe.  I would start with
>   echo 200 > /proc/sys/vm/dirty_expire_centisecs

> You said you are using ext3.  Are you using journal=data or the
> default journal=ordered ??

I'm using the default on Fedora 1, ordered data.

> Also, it would be interesting to compare nfs ops per second against
> disk i/os per second over time.
> Something like..
> 
>   while :
>   do
>     perl -ne 'if (/^proc3/)  { @a=split ; shift @a; shift @a; print eval(join("+", @a))."  ";}' /proc/net/rpc/nfsd
>     perl -ne 'if (/hda /) { @a=split; print $a[9]."\n";}' /proc/diskstats  
>     sleep 1
>   done | perl -ne '@_=split; print( ($_[0]-$a[0])." ".($_[1]-$a[1])."\n"); @a=@_;'
> 
> If the pauses correspond to periods with very low nfs ops/sec and very
> high writes per second, then it confirms that it is a disk flushing
> problem.

I'm using FC1 which has 2.4.22 as its base.  I think the 
/proc/sys/vm/dirty_expire_centisecs and the above scriptlet are
for 2.6 only.  The nfs stats work, but the /proc/diskstats file
is missing.

Do you have any suggestions for /proc/sys/vm/bdflush instead ? Here
are the current settings:

30      500     0       0       500     3000    60      20      0

> It would also be interesting to see if there was a pattern in the
> timing, particular how long the interval was between one pause and the
> next.  

I'll start keeping a note of the time of these events.

> Also getting these sets of number for different numbers of nfsd
> threads could turn your subjective impression into objective data.
> 
> NeilBrown

Thanks

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Neil Brown]

On Tuesday August 24, ian@stams.strath.ac.uk wrote:
> Neil Brown wrote:
> > On Monday August 16, ian@stams.strath.ac.uk wrote:
> > 
> >>I bumped the nfsd's up to 64 (from 32) and subjectively the problem gets 
> >>worse.  I then reduced them to 16 and things are a bit better...
> > 
> > 
> > Odd.
> > 
> >>Would changing some of the bdflush settings help at all?
> > 
> > 
> > Maybe.  I would start with
> >   echo 200 > /proc/sys/vm/dirty_expire_centisecs
> 
> > You said you are using ext3.  Are you using journal=data or the
> > default journal=ordered ??
> 
> I'm using the default on Fedora 1, ordered data.

Ok, I've seen a similar problem that was fairly specific to
journal=data.  I guess it isn't that.

> 
> > Also, it would be interesting to compare nfs ops per second against
> > disk i/os per second over time.
> > Something like..
> > 
> >   while :
> >   do
> >     perl -ne 'if (/^proc3/)  { @a=split ; shift @a; shift @a; print eval(join("+", @a))."  ";}' /proc/net/rpc/nfsd
> >     perl -ne 'if (/hda /) { @a=split; print $a[9]."\n";}' /proc/diskstats  
> >     sleep 1
> >   done | perl -ne '@_=split; print( ($_[0]-$a[0])." ".($_[1]-$a[1])."\n"); @a=@_;'
> > 
> > If the pauses correspond to periods with very low nfs ops/sec and very
> > high writes per second, then it confirms that it is a disk flushing
> > problem.
> 
> I'm using FC1 which has 2.4.22 as its base.  I think the 
> /proc/sys/vm/dirty_expire_centisecs and the above scriptlet are
> for 2.6 only.  The nfs stats work, but the /proc/diskstats file
> is missing.

Sorry, I just assumed....

You might be able to get the 'write' stats out of /proc/partitions if
CONFIG_BLK_STATS is selected, write_sectors should be the 10th field.
Alternately you would need to extract them from /proc/stat - the
disk_io line, the last number inside a parenthesised group.

> 
> Do you have any suggestions for /proc/sys/vm/bdflush instead ? Here
> are the current settings:
> 
> 30      500     0       0       500     3000    60      20      0
> 

Drop the 500 and 3000 to 100 and 500
  30      500     0       0       100     500     60      20      0

This will flush data after it is 5 seconds old instead of 30.

NeilBrown


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Greg Banks]

On Tue, Aug 24, 2004 at 10:48:14AM +0100, Ian Thurlbeck wrote:
> 
> What on earth could be writing up to 3GB of data to the drive ?
> As before the usual suspects of kjournald, kupdated, bdflush and
> nfsd turn up on the process list.
> 
> Just how big is the nfs write cache on a typical server ?

It can be most of RAM.

> Is it
> writing the whole lot one go ?

It might be.  What ratio of COMMIT to WRITE calls are you
seeing in nfsstat?  Does the export have "sync" or "async"
in its options?

Greg.
-- 
Greg Banks, R&D Software Engineer, SGI Australian Software Group.
I don't speak for SGI.


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Greg Banks wrote:
> On Tue, Aug 24, 2004 at 10:48:14AM +0100, Ian Thurlbeck wrote:
> 
>>What on earth could be writing up to 3GB of data to the drive ?
>>As before the usual suspects of kjournald, kupdated, bdflush and
>>nfsd turn up on the process list.
>>
>>Just how big is the nfs write cache on a typical server ?
> 
> 
> It can be most of RAM.
> 
> 
>>Is it
>>writing the whole lot one go ?
> 
> 
> It might be.  What ratio of COMMIT to WRITE calls are you
> seeing in nfsstat?  Does the export have "sync" or "async"
> in its options?
> 
> Greg.

Greg

Server stats since reboot Monday morning.  It is lightly
loaded mostly:

Server nfs v3:
null       getattr    setattr    lookup     access     readlink
85912   2% 1626277 46% 12375   0% 135833  3% 1295417 36% 773     0%
read       write      create     mkdir      symlink    mknod
136099  3% 151569  4% 7899    0% 64      0% 194     0% 0       0%
remove     rmdir      rename     link       readdir    readdirplus
6270    0% 37      0% 2931    0% 969     0% 266     0% 4893    0%
fsstat     fsinfo     pathconf   commit
1508    0% 890     0% 0       0% 41205   1%

So that's about 4 writes for every commit.

File system export:

/export/raid50  @unix(rw,sync,no_wdelay,hide,nocrossmnt,secure,root_squash,
no_all_squash,subtree_check,secure_locks,mapping=identity,
anonuid=-2,anongid=-2)

I've got Neil's script running to correlate disk writes with
nfs ops and these slowdown event times.  I'll post the results
in a day or so.

Thanks

Ian
-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Greg Banks]

On Wed, Aug 25, 2004 at 09:40:36AM +0100, Ian Thurlbeck wrote:
> Server stats since reboot Monday morning.  It is lightly
> loaded mostly:
> 
> Server nfs v3:
> null       getattr    setattr    lookup     access     readlink
> 85912   2% 1626277 46% 12375   0% 135833  3% 1295417 36% 773     0%
> read       write      create     mkdir      symlink    mknod
> 136099  3% 151569  4% 7899    0% 64      0% 194     0% 0       0%
> remove     rmdir      rename     link       readdir    readdirplus
> 6270    0% 37      0% 2931    0% 969     0% 266     0% 4893    0%
> fsstat     fsinfo     pathconf   commit
> 1508    0% 890     0% 0       0% 41205   1%

Yes, it is lightly loaded.  You said your block size is 8K, so
the server has seen about 1.18 GB of writes in 3 days, which is
just over twice RAM size.  How many of these slowdown events
did you see in that time?

Can you run "vmstat 1" and log the result please?

You said you have a 3ware RAID controller.  What is RAID
configuration, especially RAID level and stripe width?  What options
did you use to build the ext3 filesystem?

> So that's about 4 writes for every commit.

Ok, so your clients are doing enough COMMITs.

> File system export:
> 
> /export/raid50  @unix(rw,sync,no_wdelay,hide,nocrossmnt,secure,root_squash,
> no_all_squash,subtree_check,secure_locks,mapping=identity,
> anonuid=-2,anongid=-2)

Hmm, no "async". So much for that idea.

Greg.
-- 
Greg Banks, R&D Software Engineer, SGI Australian Software Group.
I don't speak for SGI.


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server

[Ian Thurlbeck]

Greg Banks wrote:
> On Wed, Aug 25, 2004 at 09:40:36AM +0100, Ian Thurlbeck wrote:
> 
>>Server stats since reboot Monday morning.  It is lightly
>>loaded mostly:
>>
>>Server nfs v3:
>>null       getattr    setattr    lookup     access     readlink
>>85912   2% 1626277 46% 12375   0% 135833  3% 1295417 36% 773     0%
>>read       write      create     mkdir      symlink    mknod
>>136099  3% 151569  4% 7899    0% 64      0% 194     0% 0       0%
>>remove     rmdir      rename     link       readdir    readdirplus
>>6270    0% 37      0% 2931    0% 969     0% 266     0% 4893    0%
>>fsstat     fsinfo     pathconf   commit
>>1508    0% 890     0% 0       0% 41205   1%
> 
> 
> Yes, it is lightly loaded.  You said your block size is 8K, so
> the server has seen about 1.18 GB of writes in 3 days, which is
> just over twice RAM size.  How many of these slowdown events
> did you see in that time?

Well, at least 10 per day, probably more.

> Can you run "vmstat 1" and log the result please?

Not sure what you mean. Quick snapshot follows, but I'll leave it
running and watch what happens during an "event".

procs                      memory      swap          io     system 
    cpu
  r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us 
sy wa id
  0  0  12248  43816  25148  70164    1    0   141   203  234   102  2 
2  0 96
  0  0  12248  43804  25148  70168    0    0     0     0  114    82  0 
2  0 98
  0  0  12248  43772  25180  70168    0    0     0   212  154   125  0 
1  0 99
  0  0  12248  43772  25180  70168    0    0     0     0  111    82  0 
1  0 99


> You said you have a 3ware RAID controller.  What is RAID
> configuration, especially RAID level and stripe width?  What options
> did you use to build the ext3 filesystem?

Capacity:	247.04 GB (482505216 blocks)
Write Cache:	In Use
Configuration:	Striped with Parity 64K (RAID 5)
Stripe size:	64K (65536 bytes)

Ext3 options: anyone know what the default is for Fedora Core 1?

Here is output from tune2fs -l:

tune2fs 1.34 (25-Jul-2003)
Filesystem volume name:   /spare
Last mounted on:          <not available>
Filesystem UUID:          5070c833-cdfe-408b-ae12-ee4587e7ffc4
Filesystem magic number:  0xEF53
Filesystem revision #:    1 (dynamic)
Filesystem features:      has_journal filetype needs_recovery 
sparse_super large_file
Default mount options:    (none)
Filesystem state:         clean
Errors behavior:          Continue
Filesystem OS type:       Linux
Inode count:              30162944
Block count:              60312018
Reserved block count:     3015600
Free blocks:              34369240
Free inodes:              29320077
First block:              0
Block size:               4096
Fragment size:            4096
Blocks per group:         32768
Fragments per group:      32768
Inodes per group:         16384
Inode blocks per group:   512
Filesystem created:       Mon May 19 03:28:12 2003
Last mount time:          Mon Aug 23 08:45:09 2004
Last write time:          Mon Aug 23 08:45:09 2004
Mount count:              31
Maximum mount count:      -1
Last checked:             Mon May 19 03:28:12 2003
Check interval:           0 (<none>)
Reserved blocks uid:      0 (user root)
Reserved blocks gid:      0 (group root)
First inode:              11
Inode size:               128
Journal inode:            8
Default directory hash:   tea
Directory Hash Seed:      e37b261f-2740-4f6c-a970-d4aade2b54be

Ian

> 
>>So that's about 4 writes for every commit.
> 
> 
> Ok, so your clients are doing enough COMMITs.
> 
> 
>>File system export:
>>
>>/export/raid50  @unix(rw,sync,no_wdelay,hide,nocrossmnt,secure,root_squash,
>>no_all_squash,subtree_check,secure_locks,mapping=identity,
>>anonuid=-2,anongid=-2)
> 
> 
> Hmm, no "async". So much for that idea.
> 
> Greg.


-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server (with piccies)

[Ian Thurlbeck]

Neil Brown wrote:
> On Monday August 16, ian@stams.strath.ac.uk wrote:
> 
>>I bumped the nfsd's up to 64 (from 32) and subjectively the problem gets 
>>worse.  I then reduced them to 16 and things are a bit better...
> 
> 
> Odd.
> 
> 
>>Would changing some of the bdflush settings help at all?
> 
> 
> Maybe.  I would start with
>   echo 200 > /proc/sys/vm/dirty_expire_centisecs
> 
> You said you are using ext3.  Are you using journal=data or the
> default journal=ordered ??
> 
> Also, it would be interesting to compare nfs ops per second against
> disk i/os per second over time.
> Something like..
> 
>   while :
>   do
>     perl -ne 'if (/^proc3/)  { @a=split ; shift @a; shift @a; print eval(join("+", @a))."  ";}' /proc/net/rpc/nfsd
>     perl -ne 'if (/hda /) { @a=split; print $a[9]."\n";}' /proc/diskstats  
>     sleep 1
>   done | perl -ne '@_=split; print( ($_[0]-$a[0])." ".($_[1]-$a[1])."\n"); @a=@_;'
> 
> If the pauses correspond to periods with very low nfs ops/sec and very
> high writes per second, then it confirms that it is a disk flushing
> problem.
> 
> It would also be interesting to see if there was a pattern in the
> timing, particular how long the interval was between one pause and the
> next.  
> Also getting these sets of number for different numbers of nfsd
> threads could turn your subjective impression into objective data.
> 
> NeilBrown

Neil, and others

I've gathered some useful data (I hope) on the problem. I ran a variant 
of Neil's script for 2.4 kernel for most of a day (9.30-15.00).

It's all here:

http://www.stams.strath.ac.uk/~ian/nfs/

Files:
data.all.raw	raw data, 3 columns: HH:MM:SS nfsops diskwrites
data.all.plot	massaged data, 3 columns: SECONDS nfsops diskwrites
data.all.eps	postscript plot of massaged data
data.all.gif	gif plot of massaged data

(The massaged data has had missing data filled in. Sometimes the
seconds field jumps 2 seconds. HH:MM:SS changed to seconds from start)

I think this shows no correlation between NFS ops and disk writes
with respect to these big slowdowns (the big peaks in lower graph, there
are 5). Something with a periodicity of 600 seconds is also writing to
the disk. (This was done with 32 nfsd threads, BTW)

There is another similar set of files zooming in on the first 2
events (data.zoom.*). You can see from this graph that in the disk 
writing event lasts about 50 seconds, and the client machines hang on 
NFS ops for this period (pretty annoying, I can tell you!).

Also in the directory is the output of "vmstat 1" showing one of these
events (vmstat.log).

Can anyone deduce anything from this?

Many thanks

Ian

PS: How big are these "wsect" counts in /proc/partitions in terms of bytes ?

-- 
Ian Thurlbeck                http://www.stams.strath.ac.uk/
Statistics and Modelling Science, University of Strathclyde
Livingstone Tower, 26 Richmond Street, Glasgow, UK,  G1 1XH
Tel: +44 (0)141 548 3667           Fax: +44 (0)141 552 2079



-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server (with piccies)

[Neil Brown]

On Thursday August 26, ian@stams.strath.ac.uk wrote:
> 
> Neil, and others
> 
> I've gathered some useful data (I hope) on the problem. I ran a variant 
> of Neil's script for 2.4 kernel for most of a day (9.30-15.00).

It's odd....

The data doesn't show much variation in nfs ops/second during the two
incidents you zoom in on, though you would expect that if the NFS
server were slow to respond, you would see a drop in requests (as nfsd
threads are blocked, and the clients would stop sending while waiting
for the server, at least a bit).

There are other periods of high disc writes (such as 6400:6800) where
there is a matching rise in NFS requests.  Presumably some client is
doing a lot of writing.
Do these correlate with subjective pauses too?

And the "vmstat" output shows "free" memory plummeting to 1/16th of
was it was during the quite time.  It is not surprising that this
causes lots of write activity.  This is accompanied by a sudden growth
in "cache", which seems to suggest (unless I'm misunderstanding what
"cache" and "free" mean, which isn't impossible) that lots of data was
suddenly written.  As it doesn't seem to correlate with NFS activity,
is looks like some local program on the server is suddenly writing out
lots of data and swamping the filesystem.

The "top" output doesn't seem to match any significant write traffic.

Can you get some process listings that correlate with the sudden drop
in "free" shown by vmstat and see what is happening?

> 
> PS: How big are these "wsect" counts in /proc/partitions in terms of
> bytes ?

1 sectors should be 512 bytes.

NeilBrown


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: Strange delays on NFS server (with piccies)

[Greg Banks]

On Fri, Aug 27, 2004 at 11:22:36AM +1000, Neil Brown wrote:
> On Thursday August 26, ian@stams.strath.ac.uk wrote:
> > 
> > Neil, and others
> > 
> > I've gathered some useful data (I hope) on the problem. I ran a variant 
> > of Neil's script for 2.4 kernel for most of a day (9.30-15.00).
> 
> Can you get some process listings that correlate with the sudden drop
> in "free" shown by vmstat and see what is happening?

Looking at the "vmstat.log" file....

procs                      memory      swap          io     system         cpu
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy wa id
 1  0  12284  65232  12344  86876    0    0     0   124  142   144  1  0  0 99
 0  0  12284  65228  12344  86880    0    0     4     0  127    99  0  1  0 99
 0  0  12284  65228  12344  86880    0    0     0     0  136   100  1  0  0 99
 0  0  12284  65188  12384  86884    0    0     4   192  293   475  1  1  0 98
 0  0  12284  65184  12384  86884    0    0     0     0  212   311  0  2  0 98
 0  0  12284  65176  12384  86892    0    0     0     8  152   118  1  0  0 99

Machine is basically idle, with occasional writes to disk (bo) and
no reads from disk (bi) and basically no userspace CPU activity (us).
Memory parameters are stable.  This is probably just your NFS traffic.

 0  1  12284  60104  12412  91932    0    0  2664    92  207   267  3  2  0 95
 1  5  12284  36192  12460 115552  112    0 11996  5208  427   578 11 14  0 75
 0  5  12284  27728  12516 124060   32    0  4356  2540  307   271  5  5  0 90
 1  4  12284   4500   9416 150500   76    0 27600  2140  678  1015 25 36  0 39
 1  5  12284   4480   9288 150136    8    0  2020  2304  288   252  4  4  0 92
 0  8  12284   4432   9372 149860    0    0 11016  3088  435   883 17 13  0 70
 0  9  12284   4816   8232 150472    0    0 26680  1240  711  1051 36 25  0 39
 0  9  12284   5368   8272 149796    0    0  7552  1412  326   342  9 10  0 81
 3  9  12284   4880   8148 150296    0    0  6916  2080  305   300  9 10  0 81
 1 10  12284   3256   8164 151856    0    0 14084  3244  415   521 17 16  0 67
 5 18  12284   3140   8168 151956    0    0  3672  4536  517   406  2  3  0 94

Suddenly there's lots of userspace CPU activity, a lot of write to disk,
and *lot* more read from disk, which is filling the page cache "cache"
with pages storing the new data read in; these pages are being taken from
the  "free" and "buff" states.  The reads are what I suspected when I saw
the difference in "cached" in the two "top" samples Ian posted originally.
The userspace activity means its some kind of user program, and probably
not (or not entirely) a kernelside side effect of write traffic.

So my conclusion is that this has little to do with NFS, and you've got
some kind of mostly diskbound (so it won't be obvious in "top") userspace
program doing lots and lots of writes and some more reads.  Something
doing a big grep and saving the results to disk perhaps?  If Linux had
an equivalent of IRIX' topio program it would be trivial to find the
culprit.

IOW, this is exactly what someone suggested much earlier in the
thread, and not an NFS problem.

Greg.
-- 
Greg Banks, R&D Software Engineer, SGI Australian Software Group.
I don't speak for SGI.


-------------------------------------------------------
SF.Net email is sponsored by Shop4tech.com-Lowest price on Blank Media
100pk Sonic DVD-R 4x for only $29 -100pk Sonic DVD+R for only $33
Save 50% off Retail on Ink & Toner - Free Shipping and Free Gift.
http://www.shop4tech.com/z/Inkjet_Cartridges/9_108_r285
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs