I was wondering if anyone could help me interpret the results of the
following experiment with regards to NFS softmount.
First a very brief description of my setup and test program:
I have a simple program that does a small, 512 byte, write to a file,
and print the success/failure of the IO plus the time the write took to
return, sleep one second, then loop back and write another - repeat
until ^C. The file it is writing to is on an NFS filer. During its
execution, I will disable the NFS service on the filer. The printfs of
success/failure are below.
The mount is SOFT:
172.24.0.90:/vhd1 on /mnt/snp1 type nfs
(rw,soft,timeo=1,retrans=1,addr=172.24.0.90)
When I run one instance of the program here is the output:
# ./netwrite /mnt/snp1/foo2
write block 0 (succeeded): 0.006674 secs
write block 1 (succeeded): 0.001639 secs
write block 2 (succeeded): 0.001793 secs
write block 3 (succeeded): 0.001784 secs
write block 4 (succeeded): 0.004258 secs
write block 5 (succeeded): 0.002426 secs
write block 6 (succeeded): 0.001494 secs
write block 7 (succeeded): 0.001477 secs
write block 8 (succeeded): 0.001271 secs
write block 9 (failed): 3.00014 secs
write block 10 (failed): 3.00015 secs
write block 11 (failed): 6.00012 secs
write block 12 (failed): 12.0001 secs
write block 13 (failed): 24 secs
write block 14 (failed): 47.9999 secs
write block 15 (failed): 59.9996 secs
write block 16 (failed): 35 secs
write block 17 (failed): 59.9997 secs
write block 18 (failed): 59.9997 secs
write block 19 (failed): 59.9997 secs
write block 20 (failed): 9.00012 secs
I'm curious as to why the write failure times are all over the place.
Note the timeo and retrans are both set to 1. If I run two simultaneous
instances (to different files on the same filer), the times are also all
over the place - and go as high as two minutes (curiously twice the max
as one...).
I'm using the following version of linux:
Linux wims 2.6.18-8.1.8.el5.xs4.0.0b2.102.154xen #1 SMP Tue Jul 24
16:57:36 EDT 2007 i686 i686 i386 GNU/Linux
The program is pretty simple:
#define O_DIRECT 040000
#include <stdio.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/select.h>
#include <errno.h>
#include <string.h>
#include <stdlib.h>
#include <sys/time.h>
#define ALIGN 512
#define SIZE 512
#define SEC_WAIT 1
main(int argc, char *argv[])
{
int fd;
int data=0;
char *bufptr = 0;
int result;
struct timeval tim;
struct timeval start;
struct timeval end;
if (argc != 2) {
printf("usage: %s <filename>\n", argv[0]);
goto done;
}
posix_memalign((void **)&bufptr, ALIGN, SIZE);
if (!bufptr) {
printf("failed to allocate %d bytes", SIZE);
goto done;
}
fd = open(argv[1], O_RDWR | O_CREAT | O_DIRECT, 0777);
if (!fd) {
printf("failed to open %s for write, errno=%d\n", argv[1],
errno);
goto done;
}
while (1) {
ftime(&start);
tim.tv_sec = SEC_WAIT;
tim.tv_usec = 0;
memset(bufptr, data, SIZE);
gettimeofday(&start, 0);
result = write(fd, bufptr, SIZE);
data = (data+1) & 255;
gettimeofday(&end, 0);
printf("write block %d (%s): %g secs\n",
data-1,
result < 0 ? "failed" :
"succeeded",
((end.tv_sec*1000000 + end.tv_usec)
-
(start.tv_sec*1000000 +
start.tv_usec))
/1000000.0);
select(0, 0, 0, 0, &tim);
}
done:
return 0;
}
Thanks,
Wim
WW91IGFyZSBwcm9iYWJseSBzZWVpbmcgYSBzaWRlIGVmZmVjdCBvZiB0aGUgVENQIHJlLWNvbm5l
Y3Rpb24gYmFja29mZgphbGdvcml0aG0uIEknbGwgYmV0IHlvdSB0aGF0IHRoZSBudW1iZXJzIGNo
YW5nZSBpZiB5b3UgdHJ5IFVEUC4KClRyb25kCgpPbiBUaHUsIDIwMDctMDctMjYgYXQgMTU6Mjkg
LTA3MDAsIFdpbSBDb2xnYXRlIHdyb3RlOgo+IEkgd2FzIHdvbmRlcmluZyBpZiBhbnlvbmUgY291
bGQgaGVscCBtZSBpbnRlcnByZXQgdGhlIHJlc3VsdHMgb2YgdGhlCj4gZm9sbG93aW5nIGV4cGVy
aW1lbnQgd2l0aCByZWdhcmRzIHRvIE5GUyBzb2Z0bW91bnQuCj4gCj4gIAo+IAo+IEZpcnN0IGEg
dmVyeSBicmllZiBkZXNjcmlwdGlvbiBvZiBteSBzZXR1cCBhbmQgdGVzdCBwcm9ncmFtOgo+IAo+
ICAKPiAKPiBJIGhhdmUgYSBzaW1wbGUgcHJvZ3JhbSB0aGF0IGRvZXMgYSBzbWFsbCwgNTEyIGJ5
dGUsIHdyaXRlIHRvIGEgZmlsZSwKPiBhbmQgcHJpbnQgdGhlIHN1Y2Nlc3MvZmFpbHVyZSBvZiB0
aGUgSU8gcGx1cyB0aGUgdGltZSB0aGUgd3JpdGUgdG9vawo+IHRvIHJldHVybiwgc2xlZXAgb25l
IHNlY29uZCwgdGhlbiBsb29wIGJhY2sgYW5kIHdyaXRlIGFub3RoZXIg4oCTIHJlcGVhdAo+IHVu
dGlsIF5DLiBUaGUgZmlsZSBpdCBpcyB3cml0aW5nIHRvIGlzIG9uIGFuIE5GUyBmaWxlci4gRHVy
aW5nIGl0cwo+IGV4ZWN1dGlvbiwgSSB3aWxsIGRpc2FibGUgdGhlIE5GUyBzZXJ2aWNlIG9uIHRo
ZSBmaWxlci4gVGhlIHByaW50ZnMgb2YKPiBzdWNjZXNzL2ZhaWx1cmUgYXJlIGJlbG93Lgo+IAo+
ICAKPiAKPiBUaGUgbW91bnQgaXMgU09GVDogCj4gCj4gIAo+IAo+IDE3Mi4yNC4wLjkwOi92aGQx
IG9uIC9tbnQvc25wMSB0eXBlIG5mcwo+IChydyxzb2Z0LHRpbWVvPTEscmV0cmFucz0xLGFkZHI9
MTcyLjI0LjAuOTApCj4gCj4gIAo+IAo+IFdoZW4gSSBydW4gb25lIGluc3RhbmNlIG9mIHRoZSBw
cm9ncmFtIGhlcmUgaXMgdGhlIG91dHB1dDoKPiAKPiAgCj4gCj4gIyAuL25ldHdyaXRlIC9tbnQv
c25wMS9mb28yCj4gCj4gd3JpdGUgYmxvY2sgMCAoc3VjY2VlZGVkKTogMC4wMDY2NzQgc2Vjcwo+
IAo+IHdyaXRlIGJsb2NrIDEgKHN1Y2NlZWRlZCk6IDAuMDAxNjM5IHNlY3MKPiAKPiB3cml0ZSBi
bG9jayAyIChzdWNjZWVkZWQpOiAwLjAwMTc5MyBzZWNzCj4gCj4gd3JpdGUgYmxvY2sgMyAoc3Vj
Y2VlZGVkKTogMC4wMDE3ODQgc2Vjcwo+IAo+IHdyaXRlIGJsb2NrIDQgKHN1Y2NlZWRlZCk6IDAu
MDA0MjU4IHNlY3MKPiAKPiB3cml0ZSBibG9jayA1IChzdWNjZWVkZWQpOiAwLjAwMjQyNiBzZWNz
Cj4gCj4gd3JpdGUgYmxvY2sgNiAoc3VjY2VlZGVkKTogMC4wMDE0OTQgc2Vjcwo+IAo+IHdyaXRl
IGJsb2NrIDcgKHN1Y2NlZWRlZCk6IDAuMDAxNDc3IHNlY3MKPiAKPiB3cml0ZSBibG9jayA4IChz
dWNjZWVkZWQpOiAwLjAwMTI3MSBzZWNzCj4gCj4gd3JpdGUgYmxvY2sgOSAoZmFpbGVkKTogMy4w
MDAxNCBzZWNzCj4gCj4gd3JpdGUgYmxvY2sgMTAgKGZhaWxlZCk6IDMuMDAwMTUgc2Vjcwo+IAo+
IHdyaXRlIGJsb2NrIDExIChmYWlsZWQpOiA2LjAwMDEyIHNlY3MKPiAKPiB3cml0ZSBibG9jayAx
MiAoZmFpbGVkKTogMTIuMDAwMSBzZWNzCj4gCj4gd3JpdGUgYmxvY2sgMTMgKGZhaWxlZCk6IDI0
IHNlY3MKPiAKPiB3cml0ZSBibG9jayAxNCAoZmFpbGVkKTogNDcuOTk5OSBzZWNzCj4gCj4gd3Jp
dGUgYmxvY2sgMTUgKGZhaWxlZCk6IDU5Ljk5OTYgc2Vjcwo+IAo+IHdyaXRlIGJsb2NrIDE2IChm
YWlsZWQpOiAzNSBzZWNzCj4gCj4gd3JpdGUgYmxvY2sgMTcgKGZhaWxlZCk6IDU5Ljk5OTcgc2Vj
cwo+IAo+IHdyaXRlIGJsb2NrIDE4IChmYWlsZWQpOiA1OS45OTk3IHNlY3MKPiAKPiB3cml0ZSBi
bG9jayAxOSAoZmFpbGVkKTogNTkuOTk5NyBzZWNzCj4gCj4gd3JpdGUgYmxvY2sgMjAgKGZhaWxl
ZCk6IDkuMDAwMTIgc2Vjcwo+IAo+ICAKPiAKPiAgCj4gCj4gSeKAmW0gY3VyaW91cyBhcyB0byB3
aHkgdGhlIHdyaXRlIGZhaWx1cmUgdGltZXMgYXJlIGFsbCBvdmVyIHRoZSBwbGFjZS4KPiBOb3Rl
IHRoZSB0aW1lbyBhbmQgcmV0cmFucyBhcmUgYm90aCBzZXQgdG8gMS4gSWYgSSBydW4gdHdvCj4g
c2ltdWx0YW5lb3VzIGluc3RhbmNlcyAodG8gZGlmZmVyZW50IGZpbGVzIG9uIHRoZSBzYW1lIGZp
bGVyKSwgdGhlCj4gdGltZXMgYXJlIGFsc28gYWxsIG92ZXIgdGhlIHBsYWNlIOKAkyBhbmQgZ28g
YXMgaGlnaCBhcyB0d28gbWludXRlcwo+IChjdXJpb3VzbHkgdHdpY2UgdGhlIG1heCBhcyBvbmXi
gKYpLgo+IAo+ICAKPiAKPiBJ4oCZbSB1c2luZyB0aGUgZm9sbG93aW5nIHZlcnNpb24gb2YgbGlu
dXg6Cj4gCj4gIAo+IAo+IExpbnV4IHdpbXMgMi42LjE4LTguMS44LmVsNS54czQuMC4wYjIuMTAy
LjE1NHhlbiAjMSBTTVAgVHVlIEp1bCAyNAo+IDE2OjU3OjM2IEVEVCAyMDA3IGk2ODYgaTY4NiBp
Mzg2IEdOVS9MaW51eAo+IAo+ICAKPiAKPiBUaGUgcHJvZ3JhbSBpcyBwcmV0dHkgc2ltcGxlOgo+
IAo+ICAKPiAKPiAjZGVmaW5lIE9fRElSRUNUICAgICAgICAwNDAwMDAKPiAKPiAgCj4gCj4gI2lu
Y2x1ZGUgPHN0ZGlvLmg+Cj4gCj4gI2luY2x1ZGUgPHN5cy90eXBlcy5oPgo+IAo+ICNpbmNsdWRl
IDxzeXMvc3RhdC5oPgo+IAo+ICNpbmNsdWRlIDxmY250bC5oPgo+IAo+ICNpbmNsdWRlIDx1bmlz
dGQuaD4KPiAKPiAjaW5jbHVkZSA8c3lzL3NlbGVjdC5oPgo+IAo+ICNpbmNsdWRlIDxlcnJuby5o
Pgo+IAo+ICNpbmNsdWRlIDxzdHJpbmcuaD4KPiAKPiAjaW5jbHVkZSA8c3RkbGliLmg+Cj4gCj4g
IAo+IAo+ICNpbmNsdWRlIDxzeXMvdGltZS5oPgo+IAo+ICAKPiAKPiAjZGVmaW5lIEFMSUdOIDUx
Mgo+IAo+ICNkZWZpbmUgU0laRSA1MTIKPiAKPiAjZGVmaW5lIFNFQ19XQUlUIDEKPiAKPiAgCj4g
Cj4gbWFpbihpbnQgYXJnYywgY2hhciAqYXJndltdKQo+IAo+IHsKPiAKPiAgICAgaW50IGZkOwo+
IAo+ICAKPiAKPiAgICAgaW50IGRhdGE9MDsKPiAKPiAgICAgY2hhciAqYnVmcHRyID0gMDsKPiAK
PiAgICAgaW50IHJlc3VsdDsKPiAKPiAgICAgc3RydWN0IHRpbWV2YWwgdGltOwo+IAo+ICAgICBz
dHJ1Y3QgdGltZXZhbCBzdGFydDsKPiAKPiAgICAgc3RydWN0IHRpbWV2YWwgZW5kOwo+IAo+ICAK
PiAKPiAgICAgaWYgKGFyZ2MgIT0gMikgewo+IAo+ICAgICAgICAgcHJpbnRmKCJ1c2FnZTogJXMg
PGZpbGVuYW1lPlxuIiwgYXJndlswXSk7Cj4gCj4gICAgICAgICBnb3RvIGRvbmU7Cj4gCj4gICAg
IH0KPiAKPiAgCj4gCj4gICAgIHBvc2l4X21lbWFsaWduKCh2b2lkICoqKSZidWZwdHIsIEFMSUdO
LCBTSVpFKTsKPiAKPiAgICAgaWYgKCFidWZwdHIpIHsKPiAKPiAgICAgICAgIHByaW50ZigiZmFp
bGVkIHRvIGFsbG9jYXRlICVkIGJ5dGVzIiwgU0laRSk7Cj4gCj4gICAgICAgICBnb3RvIGRvbmU7
Cj4gCj4gICAgIH0KPiAKPiAgCj4gCj4gICAgIGZkID0gb3Blbihhcmd2WzFdLCBPX1JEV1IgfCBP
X0NSRUFUIHwgT19ESVJFQ1QsIDA3NzcpOwo+IAo+ICAKPiAKPiAgICAgaWYgKCFmZCkgewo+IAo+
ICAgICAgICAgcHJpbnRmKCJmYWlsZWQgdG8gb3BlbiAlcyBmb3Igd3JpdGUsIGVycm5vPSVkXG4i
LCBhcmd2WzFdLAo+IGVycm5vKTsKPiAKPiAgICAgICAgIGdvdG8gZG9uZTsKPiAKPiAgICAgfQo+
IAo+ICAKPiAKPiAgICAgd2hpbGUgKDEpIHsKPiAKPiAgICAgICAgIGZ0aW1lKCZzdGFydCk7Cj4g
Cj4gICAgICAgICB0aW0udHZfc2VjID0gU0VDX1dBSVQ7Cj4gCj4gICAgICAgICB0aW0udHZfdXNl
YyA9IDA7Cj4gCj4gICAgICAgICBtZW1zZXQoYnVmcHRyLCBkYXRhLCBTSVpFKTsKPiAKPiAgICAg
ICAgIGdldHRpbWVvZmRheSgmc3RhcnQsIDApOwo+IAo+ICAgICAgICAgcmVzdWx0ID0gd3JpdGUo
ZmQsIGJ1ZnB0ciwgU0laRSk7Cj4gCj4gICAgICAgICBkYXRhID0gKGRhdGErMSkgJiAyNTU7Cj4g
Cj4gICAgICAgICBnZXR0aW1lb2ZkYXkoJmVuZCwgMCk7Cj4gCj4gICAgICAgICBwcmludGYoIndy
aXRlIGJsb2NrICVkICglcyk6ICVnIHNlY3NcbiIsCj4gCj4gICAgICAgICAgICAgICAgICAgICAg
ICAgICAgICAgICAgICAgIGRhdGEtMSwKPiAKPiAgICAgICAgICAgICAgICAgICAgICAgICAgICAg
ICAgICAgICAgcmVzdWx0IDwgMCA/ICJmYWlsZWQiIDoKPiAic3VjY2VlZGVkIiwKPiAKPiAgICAg
ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgKChlbmQudHZfc2VjKjEwMDAwMDAgKwo+
IGVuZC50dl91c2VjKSAtCj4gCj4gICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAg
ICAoc3RhcnQudHZfc2VjKjEwMDAwMDAgKwo+IHN0YXJ0LnR2X3VzZWMpKQo+IAo+ICAgICAgICAg
ICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgLzEwMDAwMDAuMCk7Cj4gCj4gICAgICAgICBz
ZWxlY3QoMCwgMCwgMCwgMCwgJnRpbSk7Cj4gCj4gICAgIH0KPiAKPiAgCj4gCj4gZG9uZToKPiAK
PiAgICAgcmV0dXJuIDA7Cj4gCj4gfQo+IAo+ICAKPiAKPiBUaGFua3MsCj4gCj4gIAo+IAo+IFdp
bQo+IAo+IAo+IC0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0t
LS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0KPiBUaGlzIFNGLm5ldCBlbWFpbCBpcyBzcG9uc29y
ZWQgYnk6IFNwbHVuayBJbmMuCj4gU3RpbGwgZ3JlcHBpbmcgdGhyb3VnaCBsb2cgZmlsZXMgdG8g
ZmluZCBwcm9ibGVtcz8gIFN0b3AuCj4gTm93IFNlYXJjaCBsb2cgZXZlbnRzIGFuZCBjb25maWd1
cmF0aW9uIGZpbGVzIHVzaW5nIEFKQVggYW5kIGEgYnJvd3Nlci4KPiBEb3dubG9hZCB5b3VyIEZS
RUUgY29weSBvZiBTcGx1bmsgbm93ID4+ICBodHRwOi8vZ2V0LnNwbHVuay5jb20vCj4gX19fX19f
X19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX18gTkZTIG1haWxsaXN0IC0g
TkZTQGxpc3RzLnNvdXJjZWZvcmdlLm5ldCBodHRwczovL2xpc3RzLnNvdXJjZWZvcmdlLm5ldC9s
aXN0cy9saXN0aW5mby9uZnMKCgotLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0t
LS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tClRoaXMgU0YubmV0IGVtYWlsIGlz
IHNwb25zb3JlZCBieTogU3BsdW5rIEluYy4KU3RpbGwgZ3JlcHBpbmcgdGhyb3VnaCBsb2cgZmls
ZXMgdG8gZmluZCBwcm9ibGVtcz8gIFN0b3AuCk5vdyBTZWFyY2ggbG9nIGV2ZW50cyBhbmQgY29u
ZmlndXJhdGlvbiBmaWxlcyB1c2luZyBBSkFYIGFuZCBhIGJyb3dzZXIuCkRvd25sb2FkIHlvdXIg
RlJFRSBjb3B5IG9mIFNwbHVuayBub3cgPj4gIGh0dHA6Ly9nZXQuc3BsdW5rLmNvbS8KX19fX19f
X19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX18KTkZTIG1haWxsaXN0ICAt
ICBORlNAbGlzdHMuc291cmNlZm9yZ2UubmV0Cmh0dHBzOi8vbGlzdHMuc291cmNlZm9yZ2UubmV0
L2xpc3RzL2xpc3RpbmZvL25mcwo=
Sure thing, I'll try UDP. One thing I forgot to add is that if the cable
is unplugged, the times are nicely 300ms timeouts -- which must eschew
any TCP backoff if the host is unreachable.
-----Original Message-----
From: Trond Myklebust [mailto:[email protected]]
Sent: Thursday, July 26, 2007 3:39 PM
To: Wim Colgate
Cc: [email protected]
Subject: Re: [NFS] question on the inner workings of NFS soft mount
You are probably seeing a side effect of the TCP re-connection backoff
algorithm. I'll bet you that the numbers change if you try UDP.
Trond
On Thu, 2007-07-26 at 15:29 -0700, Wim Colgate wrote:
> I was wondering if anyone could help me interpret the results of the
> following experiment with regards to NFS softmount.
>
>
>
> First a very brief description of my setup and test program:
>
>
>
> I have a simple program that does a small, 512 byte, write to a file,
> and print the success/failure of the IO plus the time the write took
> to return, sleep one second, then loop back and write another - repeat
> until ^C. The file it is writing to is on an NFS filer. During its
> execution, I will disable the NFS service on the filer. The printfs of
> success/failure are below.
>
>
>
> The mount is SOFT:
>
>
>
> 172.24.0.90:/vhd1 on /mnt/snp1 type nfs
> (rw,soft,timeo=1,retrans=1,addr=172.24.0.90)
>
>
>
> When I run one instance of the program here is the output:
>
>
>
> # ./netwrite /mnt/snp1/foo2
>
> write block 0 (succeeded): 0.006674 secs
>
> write block 1 (succeeded): 0.001639 secs
>
> write block 2 (succeeded): 0.001793 secs
>
> write block 3 (succeeded): 0.001784 secs
>
> write block 4 (succeeded): 0.004258 secs
>
> write block 5 (succeeded): 0.002426 secs
>
> write block 6 (succeeded): 0.001494 secs
>
> write block 7 (succeeded): 0.001477 secs
>
> write block 8 (succeeded): 0.001271 secs
>
> write block 9 (failed): 3.00014 secs
>
> write block 10 (failed): 3.00015 secs
>
> write block 11 (failed): 6.00012 secs
>
> write block 12 (failed): 12.0001 secs
>
> write block 13 (failed): 24 secs
>
> write block 14 (failed): 47.9999 secs
>
> write block 15 (failed): 59.9996 secs
>
> write block 16 (failed): 35 secs
>
> write block 17 (failed): 59.9997 secs
>
> write block 18 (failed): 59.9997 secs
>
> write block 19 (failed): 59.9997 secs
>
> write block 20 (failed): 9.00012 secs
>
>
>
>
>
> I'm curious as to why the write failure times are all over the place.
> Note the timeo and retrans are both set to 1. If I run two
> simultaneous instances (to different files on the same filer), the
> times are also all over the place - and go as high as two minutes
> (curiously twice the max as one...).
>
>
>
> I'm using the following version of linux:
>
>
>
> Linux wims 2.6.18-8.1.8.el5.xs4.0.0b2.102.154xen #1 SMP Tue Jul 24
> 16:57:36 EDT 2007 i686 i686 i386 GNU/Linux
>
>
>
> The program is pretty simple:
>
>
>
> #define O_DIRECT 040000
>
>
>
> #include <stdio.h>
>
> #include <sys/types.h>
>
> #include <sys/stat.h>
>
> #include <fcntl.h>
>
> #include <unistd.h>
>
> #include <sys/select.h>
>
> #include <errno.h>
>
> #include <string.h>
>
> #include <stdlib.h>
>
>
>
> #include <sys/time.h>
>
>
>
> #define ALIGN 512
>
> #define SIZE 512
>
> #define SEC_WAIT 1
>
>
>
> main(int argc, char *argv[])
>
> {
>
> int fd;
>
>
>
> int data=0;
>
> char *bufptr = 0;
>
> int result;
>
> struct timeval tim;
>
> struct timeval start;
>
> struct timeval end;
>
>
>
> if (argc != 2) {
>
> printf("usage: %s <filename>\n", argv[0]);
>
> goto done;
>
> }
>
>
>
> posix_memalign((void **)&bufptr, ALIGN, SIZE);
>
> if (!bufptr) {
>
> printf("failed to allocate %d bytes", SIZE);
>
> goto done;
>
> }
>
>
>
> fd = open(argv[1], O_RDWR | O_CREAT | O_DIRECT, 0777);
>
>
>
> if (!fd) {
>
> printf("failed to open %s for write, errno=%d\n", argv[1],
> errno);
>
> goto done;
>
> }
>
>
>
> while (1) {
>
> ftime(&start);
>
> tim.tv_sec = SEC_WAIT;
>
> tim.tv_usec = 0;
>
> memset(bufptr, data, SIZE);
>
> gettimeofday(&start, 0);
>
> result = write(fd, bufptr, SIZE);
>
> data = (data+1) & 255;
>
> gettimeofday(&end, 0);
>
> printf("write block %d (%s): %g secs\n",
>
> data-1,
>
> result < 0 ? "failed" :
> "succeeded",
>
> ((end.tv_sec*1000000 +
> end.tv_usec) -
>
> (start.tv_sec*1000000 +
> start.tv_usec))
>
> /1000000.0);
>
> select(0, 0, 0, 0, &tim);
>
> }
>
>
>
> done:
>
> return 0;
>
> }
>
>
>
> Thanks,
>
>
>
> Wim
>
>
>
------------------------------------------------------------------------
-
> This SF.net email is sponsored by: Splunk Inc.
> Still grepping through log files to find problems? Stop.
> Now Search log events and configuration files using AJAX and a
browser.
> Download your FREE copy of Splunk now >> http://get.splunk.com/
> _______________________________________________ NFS maillist -
[email protected]
https://lists.sourceforge.net/lists/listinfo/nfs
-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems? Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs
On Thu, 2007-07-26 at 15:39 -0700, Wim Colgate wrote:
> Sure thing, I'll try UDP. One thing I forgot to add is that if the cable
> is unplugged, the times are nicely 300ms timeouts -- which must eschew
> any TCP backoff if the host is unreachable.
Yup. The error values returned by the networking layer are different,
and so we don't worry so much about exponential backoff.
Trond
-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems? Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs
Bingo. UDP is consistent.
-----Original Message-----
From: Trond Myklebust [mailto:[email protected]]
Sent: Thursday, July 26, 2007 3:39 PM
To: Wim Colgate
Cc: [email protected]
Subject: Re: [NFS] question on the inner workings of NFS soft mount
You are probably seeing a side effect of the TCP re-connection backoff
algorithm. I'll bet you that the numbers change if you try UDP.
Trond
On Thu, 2007-07-26 at 15:29 -0700, Wim Colgate wrote:
> I was wondering if anyone could help me interpret the results of the
> following experiment with regards to NFS softmount.
>
>
>
> First a very brief description of my setup and test program:
>
>
>
> I have a simple program that does a small, 512 byte, write to a file,
> and print the success/failure of the IO plus the time the write took
> to return, sleep one second, then loop back and write another - repeat
> until ^C. The file it is writing to is on an NFS filer. During its
> execution, I will disable the NFS service on the filer. The printfs of
> success/failure are below.
>
>
>
> The mount is SOFT:
>
>
>
> 172.24.0.90:/vhd1 on /mnt/snp1 type nfs
> (rw,soft,timeo=1,retrans=1,addr=172.24.0.90)
>
>
>
> When I run one instance of the program here is the output:
>
>
>
> # ./netwrite /mnt/snp1/foo2
>
> write block 0 (succeeded): 0.006674 secs
>
> write block 1 (succeeded): 0.001639 secs
>
> write block 2 (succeeded): 0.001793 secs
>
> write block 3 (succeeded): 0.001784 secs
>
> write block 4 (succeeded): 0.004258 secs
>
> write block 5 (succeeded): 0.002426 secs
>
> write block 6 (succeeded): 0.001494 secs
>
> write block 7 (succeeded): 0.001477 secs
>
> write block 8 (succeeded): 0.001271 secs
>
> write block 9 (failed): 3.00014 secs
>
> write block 10 (failed): 3.00015 secs
>
> write block 11 (failed): 6.00012 secs
>
> write block 12 (failed): 12.0001 secs
>
> write block 13 (failed): 24 secs
>
> write block 14 (failed): 47.9999 secs
>
> write block 15 (failed): 59.9996 secs
>
> write block 16 (failed): 35 secs
>
> write block 17 (failed): 59.9997 secs
>
> write block 18 (failed): 59.9997 secs
>
> write block 19 (failed): 59.9997 secs
>
> write block 20 (failed): 9.00012 secs
>
>
>
>
>
> I'm curious as to why the write failure times are all over the place.
> Note the timeo and retrans are both set to 1. If I run two
> simultaneous instances (to different files on the same filer), the
> times are also all over the place - and go as high as two minutes
> (curiously twice the max as one...).
>
>
>
> I'm using the following version of linux:
>
>
>
> Linux wims 2.6.18-8.1.8.el5.xs4.0.0b2.102.154xen #1 SMP Tue Jul 24
> 16:57:36 EDT 2007 i686 i686 i386 GNU/Linux
>
>
>
> The program is pretty simple:
>
>
>
> #define O_DIRECT 040000
>
>
>
> #include <stdio.h>
>
> #include <sys/types.h>
>
> #include <sys/stat.h>
>
> #include <fcntl.h>
>
> #include <unistd.h>
>
> #include <sys/select.h>
>
> #include <errno.h>
>
> #include <string.h>
>
> #include <stdlib.h>
>
>
>
> #include <sys/time.h>
>
>
>
> #define ALIGN 512
>
> #define SIZE 512
>
> #define SEC_WAIT 1
>
>
>
> main(int argc, char *argv[])
>
> {
>
> int fd;
>
>
>
> int data=0;
>
> char *bufptr = 0;
>
> int result;
>
> struct timeval tim;
>
> struct timeval start;
>
> struct timeval end;
>
>
>
> if (argc != 2) {
>
> printf("usage: %s <filename>\n", argv[0]);
>
> goto done;
>
> }
>
>
>
> posix_memalign((void **)&bufptr, ALIGN, SIZE);
>
> if (!bufptr) {
>
> printf("failed to allocate %d bytes", SIZE);
>
> goto done;
>
> }
>
>
>
> fd = open(argv[1], O_RDWR | O_CREAT | O_DIRECT, 0777);
>
>
>
> if (!fd) {
>
> printf("failed to open %s for write, errno=%d\n", argv[1],
> errno);
>
> goto done;
>
> }
>
>
>
> while (1) {
>
> ftime(&start);
>
> tim.tv_sec = SEC_WAIT;
>
> tim.tv_usec = 0;
>
> memset(bufptr, data, SIZE);
>
> gettimeofday(&start, 0);
>
> result = write(fd, bufptr, SIZE);
>
> data = (data+1) & 255;
>
> gettimeofday(&end, 0);
>
> printf("write block %d (%s): %g secs\n",
>
> data-1,
>
> result < 0 ? "failed" :
> "succeeded",
>
> ((end.tv_sec*1000000 +
> end.tv_usec) -
>
> (start.tv_sec*1000000 +
> start.tv_usec))
>
> /1000000.0);
>
> select(0, 0, 0, 0, &tim);
>
> }
>
>
>
> done:
>
> return 0;
>
> }
>
>
>
> Thanks,
>
>
>
> Wim
>
>
>
------------------------------------------------------------------------
-
> This SF.net email is sponsored by: Splunk Inc.
> Still grepping through log files to find problems? Stop.
> Now Search log events and configuration files using AJAX and a
browser.
> Download your FREE copy of Splunk now >> http://get.splunk.com/
> _______________________________________________ NFS maillist -
[email protected]
https://lists.sourceforge.net/lists/listinfo/nfs
-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems? Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs