fs-nfs2, full tcp/ip stack problem 2

Hello,

I have found a strange problem with mounting remote filesystems using
fs-nfs2 and the full TCP/IP stack. (I need the full TCP/IP stack because
I need multicasting and also ifconfig support for other, more important
reasons). Here’s what happens:

The machine starts up and fs-nfs2 is able to mount the remote
filesystem. I use it for a while (ls, cp etc) and then go away for a
bit.

When I come back,

(1) sometimes I find that an attempt to access a remote file produces
the error “No such process” and the next attempt yields an empty
directory. At this point, I find that fs-nfs2 has simply gone away.

(2) At other times, I find that fs-nfs2 is trying to use UDP for some
reason …

I am appending the syslogd messages generated using the fs-nfs2 -v
option.

Dec 11 10:43:13 nto telnetd[270361-1]: going down on signal 18
Dec 11 10:43:13 field1 syslogd: exiting on signal 15
Dec 11 10:44:21 field1 syslogd: restart
Dec 11 10:44:22 nto portmap[221202-1]: starting…
Dec 11 10:44:25 nto Nfs[245780-1]: starting
Dec 11 10:44:25 nto Nfs[245780-1]: mounting atlas:/export/autom/aa as
/usr/aa
Dec 11 10:44:25 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 10:44:25 nto Nfs[245780-1]: RPC_OPEN: port 883 fd 4 i 883
Dec 11 10:44:25 nto Nfs[245780-1]: close vc=80560A8 fd=4
Dec 11 10:44:25 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 10:44:25 nto Nfs[245780-1]: RPC_OPEN: port 882 fd 4 i 882
Dec 11 10:44:30 nto Nfs[245780-1]: mountd port= 32800
Dec 11 10:44:30 nto Nfs[245780-1]: nfsd port= 2049
Dec 11 10:44:30 nto Nfs[245780-1]: close vc=80560A8 fd=4
Dec 11 10:44:30 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 10:44:30 nto Nfs[245780-1]: RPC_OPEN: port 881 fd 4 i 881
Dec 11 10:44:30 nto Nfs[245780-1]: got file handle for mount point
Dec 11 10:44:30 nto Nfs[245780-1]: close vc=80560A8 fd=4
Dec 11 10:44:30 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 10:44:30 nto Nfs[245780-1]: RPC_OPEN: port 880 fd 4 i 880
Dec 11 10:44:30 nto Nfs[245780-1]: connected to nfsd
Dec 11 10:44:30 nto Nfs[245780-1]: stat
Dec 11 10:44:30 nto Nfs[245780-1]: statfs
Dec 11 10:44:30 nto Nfs[245780-1]: iget: 20 80009F
Dec 11 10:44:30 nto Nfs[245780-1]: igetnew: 20 80009F
Dec 11 10:44:30 nto Nfs[245780-1]: istat: 20 80009F
Dec 11 10:44:30 nto Nfs[245780-1]: iput: 20 80009F
Dec 11 10:44:30 nto Nfs[245780-1]: atlas:/export/autom/aa mounted as
/usr/aa
Dec 11 10:44:30 nto Nfs[245780-1]: inode 8055FE8
Dec 11 10:44:30 nto Nfs[245780-1]: vput for atlas:/export/autom/aa
Dec 11 10:44:30 nto Nfs[245780-1]: mounting atlas:/export/autom/staff as
/home/a
utom
Dec 11 10:44:30 nto Nfs[245780-1]: open vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: RPC_OPEN: port 879 fd 5 i 879
Dec 11 10:44:30 nto Nfs[245780-1]: close vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: open vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: RPC_OPEN: port 878 fd 5 i 878
Dec 11 10:44:30 nto Nfs[245780-1]: mountd port= 32800
Dec 11 10:44:30 nto Nfs[245780-1]: nfsd port= 2049
Dec 11 10:44:30 nto Nfs[245780-1]: close vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: open vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: RPC_OPEN: port 877 fd 5 i 877
Dec 11 10:44:30 nto Nfs[245780-1]: got file handle for mount point
Dec 11 10:44:30 nto Nfs[245780-1]: close vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: open vc=8055BF4 fd=5
Dec 11 10:44:30 nto Nfs[245780-1]: RPC_OPEN: port 876 fd 5 i 876
Dec 11 10:44:30 nto Nfs[245780-1]: connected to nfsd
Dec 11 10:44:30 nto Nfs[245780-1]: stat
Dec 11 10:44:30 nto Nfs[245780-1]: statfs
Dec 11 10:44:30 nto Nfs[245780-1]: iget: 20 80008F
Dec 11 10:44:30 nto Nfs[245780-1]: igetnew: 20 80008F
Dec 11 10:44:30 nto Nfs[245780-1]: istat: 20 80008F
Dec 11 10:44:30 nto Nfs[245780-1]: iput: 20 80008F
Dec 11 10:44:30 nto Nfs[245780-1]: atlas:/export/autom/staff mounted as
/home/au
tom
Dec 11 10:44:30 nto Nfs[245780-1]: inode 8055B34
Dec 11 10:44:30 nto Nfs[245780-1]: vput for atlas:/export/autom/staff
Dec 11 10:44:53 nto Nfs[245780-1]: io_open rcvid5 (
atlas:/export/autom/aa/ )
8055FE8
Dec 11 10:44:53 nto Nfs[245780-1]: igetbyname: 6
Dec 11 10:44:53 nto Nfs[245780-1]: igetbyname: before while:
Dec 11 10:44:53 nto Nfs[245780-1]: iget: 20 80009F
Dec 11 10:44:53 nto Nfs[245780-1]: iget: need to restat 3A34236E
3A342385
Dec 11 10:44:53 nto Nfs[245780-1]: vc for atlas:/export/autom/aa
Dec 11 10:44:53 nto Nfs[245780-1]: vget: vc=80560A8 fd=4
Dec 11 10:44:53 nto Nfs[245780-1]: istat: 20 80009F
Dec 11 10:44:53 nto Nfs[245780-1]: vput for atlas:/export/autom/aa
Dec 11 10:44:53 nto Nfs[245780-1]: iput: 20 80009F
Dec 11 10:44:53 nto Nfs[245780-1]: io_open returning EOK to rcvid 5
Dec 11 10:44:53 nto Nfs[245780-1]: stat()
Dec 11 10:44:53 nto Nfs[245780-1]: io_close: 20
Dec 11 10:44:53 nto Nfs[245780-1]: io_open rcvid5 (
atlas:/export/autom/aa/ )
8055FE8
Dec 11 10:44:53 nto Nfs[245780-1]: igetbyname: 7
Dec 11 10:44:53 nto Nfs[245780-1]: igetbyname: before while:
Dec 11 10:44:53 nto Nfs[245780-1]: iget: 20 80009F
Dec 11 10:44:53 nto Nfs[245780-1]: iput: 20 80009F
Dec 11 10:44:53 nto Nfs[245780-1]: io_open returning EOK to rcvid 5
Dec 11 10:44:53 nto Nfs[245780-1]: stat()
Dec 11 10:44:53 nto Nfs[245780-1]: read
Dec 11 10:44:53 nto Nfs[245780-1]: vc for atlas:/export/autom/aa
Dec 11 10:44:53 nto Nfs[245780-1]: vget: vc=80560A8 fd=4
Dec 11 10:44:53 nto Nfs[245780-1]: readdir 20
Dec 11 10:44:53 nto Nfs[245780-1]: bget: start
Dec 11 10:44:53 nto Nfs[245780-1]: bget: need new buf for blkno 0 ino
20
Dec 11 10:44:53 nto Nfs[245780-1]: bget: cur 0 max 250
Dec 11 10:44:53 nto Nfs[245780-1]: reading blk 0 len 2150
Dec 11 10:44:53 nto Nfs[245780-1]: blk 0 is valid with len 1060 bsize
2150
Dec 11 10:44:53 nto Nfs[245780-1]: readdir: bsize 2150 nbytes 2048
buffer 7fa55e
4 buf 8057f40 buf.data 805ff00
Dec 11 10:44:53 nto Nfs[245780-1]: .
Dec 11 10:44:53 nto Nfs[245780-1]: …

Dec 11 10:44:53 nto Nfs[245780-1]: lost+found
Dec 11 10:44:53 nto Nfs[245780-1]: pkg
Dec 11 10:44:53 nto Nfs[245780-1]: lib
Dec 11 10:44:53 nto Nfs[245780-1]: bin
Dec 11 10:44:53 nto Nfs[245780-1]: man
Dec 11 10:44:53 nto Nfs[245780-1]: tmp
Dec 11 10:44:53 nto Nfs[245780-1]: include
Dec 11 10:44:53 nto Nfs[245780-1]: proj
Dec 11 10:44:53 nto Nfs[245780-1]: lynx
Dec 11 10:44:53 nto Nfs[245780-1]: www
Dec 11 10:44:53 nto Nfs[245780-1]: pub
Dec 11 10:44:53 nto Nfs[245780-1]: etc
Dec 11 10:44:53 nto Nfs[245780-1]: admin
Dec 11 10:44:53 nto Nfs[245780-1]: linux
Dec 11 10:44:53 nto Nfs[245780-1]: data
Dec 11 10:44:53 nto Nfs[245780-1]: index.olds
Dec 11 10:44:53 nto Nfs[245780-1]: autom.htm
Dec 11 10:44:53 nto Nfs[245780-1]: info
Dec 11 10:44:53 nto Nfs[245780-1]: index.htm
Dec 11 10:44:53 nto Nfs[245780-1]: intranet
Dec 11 10:44:53 nto Nfs[245780-1]: index.html
Dec 11 10:44:53 nto Nfs[245780-1]: share
Dec 11 10:44:53 nto Nfs[245780-1]: index.old

Dec 11 11:10:57 nto Nfs[245780-1]: io_open rcvid5 (
atlas:/export/autom/aa/ )
8055FE8
Dec 11 11:10:57 nto Nfs[245780-1]: igetbyname: 6
Dec 11 11:10:57 nto Nfs[245780-1]: igetbyname: before while:
Dec 11 11:10:57 nto Nfs[245780-1]: iget: 20 80009F
Dec 11 11:10:57 nto Nfs[245780-1]: iget: need to restat 3A3426B1
3A3429A1
Dec 11 11:10:57 nto Nfs[245780-1]: vc for atlas:/export/autom/aa
Dec 11 11:10:57 nto Nfs[245780-1]: vget: vc=80560A8 fd=4
Dec 11 11:10:58 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
return 0
(expected 4): No such process
Dec 11 11:10:58 nto Nfs[245780-1]: sendmsg to [atlas:/export/autom/aa]
on fd [-1
] failed: Bad file descriptor
Dec 11 11:10:58 nto Nfs[245780-1]: mounting atlas:/export/autom/aa as
/usr/aa
Dec 11 11:10:58 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 11:10:58 nto Nfs[245780-1]: RPC_OPEN: port 871 fd 4 i 871
Dec 11 11:10:58 nto Nfs[245780-1]: close vc=80560A8 fd=4
Dec 11 11:10:58 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 11:10:58 nto Nfs[245780-1]: RPC_OPEN: port 870 fd 4 i 870
Dec 11 11:10:58 nto Nfs[245780-1]: mountd port= 32800
Dec 11 11:11:00 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
return 0
(expected 4): Interrupted function call
Dec 11 11:11:00 nto Nfs[245780-1]: sendmsg to [atlas:/export/autom/aa]
on fd [-1
] failed: Bad file descriptor
Dec 11 11:11:00 nto Nfs[245780-1]: portmap failure No such process
Dec 11 11:11:00 nto Nfs[245780-1]: falling back to UDP
Dec 11 11:11:00 nto Nfs[245780-1]: open vc=80560A8 fd=4
Dec 11 11:11:00 nto Nfs[245780-1]: RPC_OPEN: port 869 fd 4 i 869
Dec 11 11:11:00 nto Nfs[245780-1]: RPC_SEND: recv asking len= 50
Dec 11 11:11:01 nto Nfs[245780-1]: RPC_SEND: recv rx’d len= FFFFFFFF
Dec 11 11:11:01 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
timed out
xid 3A34237E
Dec 11 11:11:01 nto Nfs[245780-1]: RPC_SEND: recv asking len= 50
Dec 11 11:11:03 nto Nfs[245780-1]: RPC_SEND: recv rx’d len= FFFFFFFF
Dec 11 11:11:03 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
timed out
xid 3A34237E
Dec 11 11:11:03 nto Nfs[245780-1]: RPC_SEND: recv asking len= 50
Dec 11 11:11:07 nto Nfs[245780-1]: RPC_SEND: recv rx’d len= FFFFFFFF
Dec 11 11:11:07 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
timed out
xid 3A34237E
Dec 11 11:11:07 nto Nfs[245780-1]: RPC_SEND: recv asking len= 50
Dec 11 11:11:15 nto Nfs[245780-1]: RPC_SEND: recv rx’d len= FFFFFFFF
Dec 11 11:11:15 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
timed out
xid 3A34237E


Pavan Sikka
CSIRO Manufacturing Science and Technology Telephone: +61 7 3327 4652
Qld Centre for Advanced Technologies Facsimile: +61 7 3327 4455
Technology Court, Pullenvale QLD 4069 Email:
p.sikka@cat.csiro.au
Postal: P O Box 883, Kenmore QLD 4069 Web: www.cat.csiro.au/cmst

Dec 11 11:10:58 nto Nfs[245780-1]: recv from [atlas://export/autom/aa]
return 0

fs-nfs2 got a reply contains zero bytes data (i.e. no data after tcp/udp header),
which is unusual. Let us find what happened there.

(expected 4): No such process
Dec 11 11:10:58 nto Nfs[245780-1]: sendmsg to [atlas:/export/autom/aa]
on fd [-1
] failed: Bad file descriptor

Sending out a request failed as an invalid fd provided.
We will find out what happened there.
Thanks again for your help and important information.
Weijie


Pavan Sikka
CSIRO Manufacturing Science and Technology Telephone: +61 7 3327 4652
Qld Centre for Advanced Technologies Facsimile: +61 7 3327 4455
Technology Court, Pullenvale QLD 4069 Email:
p.sikka@cat.csiro.au
Postal: P O Box 883, Kenmore QLD 4069 Web: > www.cat.csiro.au/cmst