kernel nfsd
Subsystems (3)
Hello Trond, hello all,
can you explain what this means:
kernel: nfsd-fh: found a name that I didn't expect: <filename>
Should something be done against it, or is it simply informative?
Comes up on 2.4.20 kernel based nfs-server quite often. Exported FS is reiserfs sized about 500 GB.
Signature · 2 lines
Regards, Stephan
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Stephan von Krawczynski <[email protected]> writes:
> Hello Trond, hello all, can you explain what this means:
> kernel: nfsd-fh: found a name that I didn't expect: <filename>
> Should something be done against it, or is it simply > informative?
The comment in the code just above the printk() reads
/* Now that IS odd. I wonder what it means... */
Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
Cheers,
Trond
Quoted 9 lines · On Tue, 18 Mar 2003 16:31:43 +0100 Trond Myklebust…
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Stephan von Krawczynski <[email protected]> writes:
> Hello Trond, hello all, can you explain what this means:
> kernel: nfsd-fh: found a name that I didn't expect: <filename>
> Should something be done against it, or is it simply > informative?
Quoted 6 lines
The comment in the code just above the
printk()reads/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
Signature · 2 lines
Regards, Stephan
Hello!
Quoted 6 lines · Stephan von Krawczynski
Quoted 4 lines
The comment in the code just above the
printk()reads/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
What is the typical usage pattern for files whose names are printed? Are they created/deleted often by multiple clients/processes by any chance?
Bye,
Oleg
Quoted 8 lines · On Tue, 18 Mar 2003 19:07:33 +0300 Oleg Drokin <[email protected]> wrote:
Hello!
Quoted 4 lines · Stephan von Krawczynski
Quoted 4 lines
The comment in the code just above the
printk()reads/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
Quoted 5 lines
Quoted 2 lines
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
What is the typical usage pattern for files whose names are printed? Are they created/deleted often by multiple clients/processes by any chance?
This is a nfs-server who serves web-servers (apache). I find a lot of these messages, but they (upto now) only point to 3 different filenames. And these are in fact all directories. The box never crashed and has currently 20 days uptime. It is dual P-III and has 6 GB of RAM.
The questionable directories were created long before they first showed this message and have never changed (regarding name-change). Their contents were possible changed but surely not often meaning no more than once a day or once a week.
It may well occur that multiple nfs-client systems _read_ them, as well as multiple processes on one client.
The nfs-clients are 2.4.19 boxes and one 2.2.21.
Signature · 2 lines
Regards, Stephan
Quoted 17 lines · On Tue, 18 Mar 2003 17:28:25 +0100 Stephan von Krawczynski <[email protected]>…
Quoted 8 lines · On Tue, 18 Mar 2003 19:07:33 +0300 Oleg Drokin <[email protected]> wrote:
Hello!
Quoted 4 lines · Stephan von Krawczynski
Quoted 4 lines
The comment in the code just above the
printk()reads/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
Quoted 5 lines
Quoted 2 lines
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
What is the typical usage pattern for files whose names are printed? Are they created/deleted often by multiple clients/processes by any chance?
Quoted 11 lines
This is a nfs-server who serves web-servers (apache). I find a lot of these messages, but they (upto now) only point to 3 different filenames. And these are in fact all directories. The box never crashed and has currently 20 days uptime. It is dual P-III and has 6 GB of RAM.
The questionable directories were created long before they first showed this message and have never changed (regarding name-change). Their contents were possible changed but surely not often meaning no more than once a day or once a week.
It may well occur that multiple nfs-client systems _read_ them, as well as multiple processes on one client.
The nfs-clients are 2.4.19 boxes and one 2.2.21.
And one addition:
They are all second level, meaning look like:
kernel: nfsd-fh: found a name that I didn't expect: libyen2000/pics
(where pics is a directory, too)
Signature · 2 lines
Regards, Stephan
Quoted 32 lines · On Tue, 18 Mar 2003 17:41:06 +0100 Stephan von Krawczynski <[email protected]>…
Quoted 17 lines · On Tue, 18 Mar 2003 17:28:25 +0100 Stephan von Krawczynski <[email protected]>…
Quoted 8 lines · On Tue, 18 Mar 2003 19:07:33 +0300 Oleg Drokin <[email protected]> wrote:
Hello!
Quoted 4 lines · Stephan von Krawczynski
Quoted 4 lines
The comment in the code just above the
printk()reads/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
Quoted 5 lines
Quoted 2 lines
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
What is the typical usage pattern for files whose names are printed? Are they created/deleted often by multiple clients/processes by any chance?
Quoted 11 lines
This is a nfs-server who serves web-servers (apache). I find a lot of these messages, but they (upto now) only point to 3 different filenames. And these are in fact all directories. The box never crashed and has currently 20 days uptime. It is dual P-III and has 6 GB of RAM.
The questionable directories were created long before they first showed this message and have never changed (regarding name-change). Their contents were possible changed but surely not often meaning no more than once a day or once a week.
It may well occur that multiple nfs-client systems _read_ them, as well as multiple processes on one client.
The nfs-clients are 2.4.19 boxes and one 2.2.21.
Quoted 2 lines
And one addition:
They are all second level, meaning look like:
Please ignore this rather silly comment. One should read code before commenting ;-)
Signature · 2 lines
Regards, Stephan
Quoted 8 lines · Oleg Drokin
Hello!
Quoted 5 lines · Stephan von Krawczynski
Quoted 4 lines
The comment in the code just above the
printk()reads/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
Quoted 6 lines
Quoted 2 lines
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
What is the typical usage pattern for files whose names are printed? Are they created/deleted often by multiple clients/processes by any chance?
Hi,
we also sometimes see those messages. In our case it seems to appears rather often for the local/share/perl directory of our /usr/local directory:
nfsd-fh: found a name that I didn't expect: share/perl
This directory is certainly never deleted when this message appears, actually data are very, very seldem written to it.
Once this message also appeared for a file:
servicetypes/kdeveloplanguagesupport.desktop
I can't tell you how often kde deletes this file.
Please ask if you need more information.
Bernd
Hello!
Quoted 3 lines · Bernd Schubert
we also sometimes see those messages. In our case it seems to appears rather often for the local/share/perl directory of our
/usr/localdirectory:
nfsd-fh: found a name that I didn't expect: share/perl
Do you also use reiserfs for your /usr/local filesystem?
Bye,
Oleg
Quoted 9 lines · Oleg Drokin
Hello!
Quoted 3 lines · Bernd Schubert
we also sometimes see those messages. In our case it seems to appears rather often for the local/share/perl directory of our
/usr/local
directory: nfsd-fh: found a name that I didn't expect: share/perlDo you also use reiserfs for your
/usr/localfilesystem?
Yes of course, otherwise I wouldn't have replied to this thread.
Best regards,
Bernd
Quoted 14 lines · On Tuesday March 18, [email protected] wrote:
Quoted 11 lines · On Tue, 18 Mar 2003 16:31:43 +0100 Trond Myklebust…
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Stephan von Krawczynski <[email protected]> writes:
> Hello Trond, hello all, can you explain what this means:
> kernel: nfsd-fh: found a name that I didn't expect: <filename>
> Should something be done against it, or is it simply > informative?
The comment in the code just above the
printk()reads
Quoted 7 lines
Quoted 4 lines
/* Now that IS odd. I wonder what it means... */Looks like you and Neil (and possibly the ReiserFS team) might want to have a chat...
I'm all for it. Who has a glue? I have in fact tons of these messages, it's a pretty large nfs server.
When knfsd gets a request for a filehandle which refers to an object that isn't in the dcache, it needs to get it into the dcache. This involves finding it's name and splicing it in.
It gets hold of an inode for the parent directory (don't worry how) and reads through that directory looking for a name with the right inode number. When it finds the name, it checks to see that the name isn't already in the dcache under that directory. As the object with that name isn't in the dcache you would expect the name not to be their either. This message indicates that the name was there.
I think there is enough locking in place so that a race between one process adding the name and another process looking up the name for an object should not stumble over each other - both hold i_sem for the directory. So I don't think that would be the cause.
Maybe this is reiserfs specific. Has anyone seen it on a non-reiserfs filesystem? Possibly reiserfs does something funny with inode numbers that is confusing the name lookup.
If it doesn't seem to correlate with other symptoms, I probably wouldn't worry about it.
2.5 does all this quite differently so shouldn't have the same problem (it certainly doesn't contain the same error message).
NeilBrown
Quoted 6 lines · On Wed, 19 Mar 2003 09:09:49 +1100 Neil Brown <[email protected]> wrote:
Maybe this is reiserfs specific. Has anyone seen it on a non-reiserfs filesystem? Possibly reiserfs does something funny with inode numbers that is confusing the name lookup.
If it doesn't seem to correlate with other symptoms, I probably wouldn't worry about it.
I re-checked the logfile and it looks like the read request (or open request) is in fact failing, so something should be done. The apache-log looks like:
[Mon Mar 17 22:55:56 2003] [crit] [client w.x.y.z] (17)File exists: /a/b/c/d/e
pcfg_openfile: unable to check htaccess file, ensure it is readable
The corresponding nfs message is:
Mar 17 22:55:55 me kernel: nfsd-fh: found a name that I didn't expect: c/d
Signature · 2 lines
Regards, Stephan
[BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
In reply to Stephan von KrawczynskiHello Trond, hello all,
I'm suffering from the long present bug in the nfs client.
This bug cause programs reading from NFS volume to stuck in D state forever.
This bug revealed only when client talks to NFS server with 3COM 3C905 NIC's ( well I'v triggered it with Intel eepro card too, but you have to wait) and never with cheap slower cards like RTLxxxx, NE2000 clones. It happens infrequently but inevitably. It happens more frequentlly on 2.4.17 kernel then on 2.4.21-pre5, when compiled by gcc 3.2.1 then gcc 2.95.3. Trond's NFS patches doesn't help on both kernels. It's not due to packets loss (ok, it happens some times but rarely), it happens on both 10 and 100 Mbps. This happens only on my StrongARM board (similar to Brutus) with SMC's LAN91C111 ethernet chip. I 've not able to reproduce this on PC, but i've head about very similar case: http://www.uwsg.iu.edu/hypermail/linux/kernel/0206.0/0066.html
It triggered simply by 'ls -lR /home>/dev/null&' and takes ~ half a minute to happend.
If i insert a few printk's in the interrupt handler for NIC, it's gone !!!
IMHO this is due to the race in the nfs client.
Look at some logs from my system:
sh-2.03# mount
rootfs on / type rootfs (rw)/dev/mtdblock4 on / type jffs2 (rw)
none on /proc type proc (rw)
none on /tmp type tmpfs (rw)
none on /dev/pts type devpts (rw)
infracvs:/group on /group type nfs (rw,v2,rsize=4096,wsize=4096,soft,intr,udp,lock,addr=infracvs) serov:/home on /home type nfs (rw,v3,rsize=4096,wsize=4096,soft,intr,udp,lock,addr=serov)
sh-2.03# ps
PID Uid Stat Command 1 root S init 2 root S [keventd] 3 root S [ksoftirqd_CPU0] 4 root S [kswapd] 5 root S [bdflush] 6 root S [kupdated] 7 root S [mtdblockd] 8 root S [jffs2_gcd_mtd4] 102 root S dhcpcd 111 bin S portmap 113 root S [rpciod] 114 root S [lockd] 124 root S klogd 138 root S /usr/sbin/inetd 143 root S /www/sbin/sshd -f /www/etc/sshd_config 152 root S init 153 root S sh -login -i 158 root D ls -lR /home 159 root D ls -lR /home 179 root D ls -lR /home 183 root R ps
Part of output from Magic SysRq t with decoded symbols:
ls D C001EB8C 3216 165 153 (NOTLB)
Function entered at [<c001e990>] from [<c0109b14>]
schedule __rpc_execute
I've used /proc/sys/sunrpc/rpc_debug and /proc/sys/sunrpc/nfs_debug to get some info, it was nothing interesting in it exept the fact that rpc request wich was constantly reused after 'ls' stuck is appeared inthe following message in the --rqstp- column. sh-2.03# echo 1 > /proc/sys/sunrpc/rpc_debug
sh-2.03# dmesg -c -s 66666
-pid- proc flgs status -client- -prog- --rqstp- -timeout -rpcwait -action- --exit--
20429 0001 0000 000000 c0eda960 100003 c8f89218 00000000 <NULL> c0105d5c 0 10052 0001 0000 000000 c0eda960 100003 c8f8918c 00000000 <NULL> c0105d5c 0 06851 0001 0000 000000 c0eda960 100003 c8f89100 00000000 <NULL> c0105d5c 0 00673 0004 0000 000000 c0eda960 100003 c8f89074 00000000 <NULL> c0105d5c 0
00368 0000 0081 -00110 c0eda960 100003 0 00003000 nfs_flushd c006e290 c006e3c8
00002 0000 0081 -00110 c0e310a0 100003 0 00003000 nfs_flushd c006e290 c006e3c8
c006e290 t nfs_flushdc006e3c8 t nfs_flushd_exitc0105d5c t call_status
[BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Vladimir Serov <[email protected]> writes:
> interrupt handler for NIC, it's gone !!! IMHO this is due to > the race in the nfs client.
Why would an NFS race show up only on PPC? Do you have a tcpdump?
Cheers,
Trond
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 10 lines · Trond Myklebust
Quoted 6 lines
Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
" " == Vladimir Serov <[email protected]> writes:
interrupt handler for NIC, it's gone !!! IMHO this is due to the race in the nfs client.
Why would an NFS race show up only on PPC? Do you have a tcpdump?
Hi , Trond
As I wrote , another persone has similar problems on PC's, as to me it was a big suprise to see such a problem in nfs, cause i'm using it for over 10 yers in a different setups's OS's , etc. Yes I have tcpdump , and as i wrote, nothing wrong is going on with packet receiption, where is now corrupted packets , no error messages, NOTHING !!!! Just RPC request gets lost, I mean not correctly connected to the some queue or caller. It last for over a year , and is a big pain in the ass of company i'm working for now.
With best regards, Vladimir.
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Vladimir Serov <[email protected]> writes:
> Trond Myklebust wrote:
>>>>>>> " " == Vladimir Serov <[email protected]> writes:
>>>>>>>
>>
>> > interrupt handler for NIC, it's gone !!! IMHO this is due to >> > the race in the nfs client.
>>
>> Why would an NFS race show up only on PPC? Do you have a >> tcpdump?
>>
> Hi , Trond As I wrote , another persone has similar problems on > PC's, as to me it was a big suprise to see such a problem in
No that wasn't the same problem. IIRC that other person had faulty hardware. To my knowledge, there are no outstanding problems with hangs under 2.4.x.
> nfs, cause i'm using it for over 10 yers in a different > setups's OS's , etc. Yes I have tcpdump , and as i wrote, > nothing wrong is going on with packet receiption, where is now > corrupted packets , no error messages, NOTHING !!!! Just RPC
Can I see that tcpdump in order to judge that for myself?
Cheers,
Trond
A message that is not in the archive (sent off-list or not yet received): [email protected]
A message that is not in the archive (sent off-list or not yet received): [email protected]
A message that is not in the archive (sent off-list or not yet received): [email protected]
A message that is not in the archive (sent off-list or not yet received): [email protected]
A message that is not in the archive (sent off-list or not yet received): [email protected]
A message that is not in the archive (sent off-list or not yet received): [email protected]
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Hi Trond ,
I'm calling you again, to the ask for the help with the same problem on ARM nfs client.
I've managed to trace this problem down to the the specific routine where control reaches uninterruptible sleep. It's in 'fs/nfs/inode.c' : __nfs_revalidate_inode(struct nfs_server *server, struct inode *inode):
while (NFS_REVALIDATING(inode)) {
dfprintk(PAGECACHE, "NFS: nfs_wait_on_inode()\n");
status = nfs_wait_on_inode(inode, NFS_INO_REVALIDATING);
if (status < 0)
goto out_nowait;
if (time_before(jiffies,NFS_READTIME(inode)+NFS_ATTRTIMEO(inode))) {
status = NFS_STALE(inode) ? -ESTALE : 0;
goto out_nowait;
}
}control sleeps forever in nfs_wait_on_inode(). I can't bet, but as far as i broused dmesg output every call to nfs_wait_on_inode() in this place leads to uninterruptible sleep forever. I like to notice that inode->i_count i'm printing is 2 when this problem happens instead of 1 when things are OK. Also the rpc client in this request is c0d75060 which is mentioned in rpc queue status:
-pid- proc flgs status -client- -prog- --rqstp- -timeout -rpcwait -action- --exit--
09150 0001 0000 000000 c0d75060 100003 c8f99074 00000000 <NULL> c00f17b8 0
00683 0000 0081 -00110 c0d75060 100003 0 00030000 nfs_flushd c0066c04 c0066d3c
00002 0000 0081 -00110 c8f93c80 100003 0 00030000 nfs_flushd c0066c04 c0066d3c
my current kernel is 2.4.21-pre6 based. I'm using HARD mounted nfs volume now !!!
here is the tail of last dmesg output:
NFS: revalidating (9/1246183/1246183 count=1)
NFS: lock_kernel()
NFS: exit while (NFS_REVALIDATING(inode))
NFS call getattr
RPC: 25429 new task procpid 179 RPC: 25429 looking up UNIX cred RPC: 25429 rpc_execute flgs 0 RPC: 25429 deleting timer RPC: 25429 call_start nfs3 proc 1 (sync) RPC: 25429 deleting timer RPC: 25429 call_reserve RPC: 25429 reserved req c8f99100 xid 00011353 RPC: 25429 deleting timer RPC: 25429 call_reserveresult (status 0) RPC: 25429 deleting timer RPC: 25429 call_allocate (status 0) RPC: allocated buffer c8e70800 RPC: 25429 deleting timer RPC: 25429 call_encode (status 0) RPC: 25429 marshaling UNIX cred c0db30a0 RPC: 25429 deleting timer RPC: 25429 call_bind xprt c8f99000 is connected RPC: 25429 deleting timer RPC: 25429 call_transmit (status 0) RPC: 25429 xprt_transmit(11353) RPC: 25429 xprt_cwnd_limited cong = 0 cwnd = 512 RPC: udp_data_ready... RPC: udp_data_ready client c8f99000 RPC: 25429 received reply RPC: cong 256, cwnd was 512, now 512 RPC: 25429 has input (112 bytes) RPC: xprt_sendmsg(0) = 104 RPC: 25429 xmit complete RPC: wake_up_next(c8f9904c "xprt_resend") RPC: wake_up_next(c8f99040 "xprt_sending") RPC: 25429 deleting timer RPC: 25429 call_status (status 112) RPC: 25429 deleting timer RPC: 25429 call_decode (status 112) RPC: 25429 validating UNIX cred c0db30a0 RPC: 25429 call_decode result 0 decode 0xc0071920 RPC: 25429 deleting timer RPC: 25429 exit() = 0 RPC: 25429 release task RPC: 25429 disabling timer RPC: 25429 deleting timer RPC: wake_up_next(c8f9904c "xprt_resend") RPC: wake_up_next(c8f99040 "xprt_sending") RPC: 25429 release request c8f99100 RPC: wake_up_next(c8f99064 "xprt_backlog") RPC: 25429 releasing UNIX cred c0db30a0 RPC: rpc_release_client(c0d75060, 3) NFS reply getattr NFS: nfs_refresh_inode(inode, &fattr) NFS: refresh_inode(9/1246183 ct=1 info=0x6) NFS: (9/1246183) revalidation complete NFS: out: NFS: out_nowait: NFS: unlock_kernel() NFS: dentry_delete(linux/802_11.h, 0) RPC: looking up UNIX cred RPC: looking up UNIX cred RPC: looking up UNIX cred RPC: looking up UNIX cred RPC: looking up UNIX cred RPC: looking up UNIX cred RPC: looking up UNIX cred NFS: revalidating (9/1246184/1246184 count=2) NFS: lock_kernel() NFS: nfs_wait_on_inode() NFS: nfs_wait_on_inode: clnt=c0d75060 nfs_wait_event() UN interruptible
Cheers, Vladimir.
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Vladimir Serov <[email protected]> writes:
> when things are OK. Also the rpc client in this request is
> c0d75060 which is mentioned in rpc queue status:
> -pid- proc flgs status -client- -prog- --rqstp- -timeout
> -rpcwait -action- --exit--
> 09150 0001 0000 000000 c0d75060 100003 c8f99074 00000000
> <NULL> c00f17b8 0Looks like there is a hanging GETATTR call from another process that is blocking your process.
Which procedure does c00f17b8 correspond to? You can use gdb on the 'vmlinux' file (NB!: *not* the compressed vmlinuz), then 'disassemble 0xc00f17b8').
Cheers,
Trond
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Hi Trond,
Quoted 12 lines
Quoted 7 lines
when things are OK. Also the rpc client in this request is
c0d75060which is mentioned in rpc queue status:(quoted diff) +0
-2-pid- proc flgs status -client- -prog- --rqstp- -timeout -rpcwait -action- --exit--09150 0001 0000 000000
c0d75060100003c8f9907400000000 <NULL>c00f17b80Looks like there is a hanging GETATTR call from another process that is blocking your process.
Quoted 2 lines
Which procedure does
c00f17b8correspond to?
from the System.map :
c00f17b8 t call_status
Regards, Vladimir.
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 8 lines
Quoted 8 lines
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Vladimir Serov <[email protected]> writes:
Looks like there is a hanging GETATTR call from another process that is blocking your process.
Which procedure does
c00f17b8correspond to?
> from the System.map :
> c00f17b8 t call_status
OK. Looks as if the process isn't being woken up in rpc_execute(). Does the following make any difference?
Cheers,
Trond
include/linux/sunrpc/sched.h renamed from include/linux/sunrpc/sched.h.orig +6 -1
@@ -128,7 +128,12 @@#define RPC_IS_RUNNING (t) (test_bit(RPC_TASK_RUNNING, &(t)->tk_runstate))#define rpc_set_running (t) (set_bit(RPC_TASK_RUNNING, &(t)->tk_runstate)) -#define rpc_clear_running (t) (clear_bit(RPC_TASK_RUNNING, &(t)->tk_runstate)) +#define rpc_clear_running (t) \ + do { \ + smp_mb__before_clear_bit(); \ + clear_bit(RPC_TASK_RUNNING, &(t)->tk_runstate); \ + smp_mb__after_clear_bit(); \ + } while(0)#define rpc_set_sleeping (t) (set_bit(RPC_TASK_SLEEPING, &(t)->tk_runstate))
include/linux/sunrpc/xprt.h renamed from include/linux/sunrpc/xprt.h.orig +6 -1
@@ -200,7 +200,12 @@#define xprt_connected (xp) (test_bit(XPRT_CONNECT, &(xp)->sockstate))#define xprt_set_connected (xp) (set_bit(XPRT_CONNECT, &(xp)->sockstate))#define xprt_test_and_set_connected (xp) (test_and_set_bit(XPRT_CONNECT, &(xp)->sockstate)) -#define xprt_clear_connected (xp) (clear_bit(XPRT_CONNECT, &(xp)->sockstate)) +#define xprt_clear_connected (xp) \ + do { \ + smp_mb__before_clear_bit(); \ + clear_bit(XPRT_CONNECT, &(xp)->sockstate); \ + smp_mb__after_clear_bit(); \ + } while(0)#endif /* __KERNEL__*/
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
In reply to a message not in the archiveHi Trond , Hi Russell,
I have some new info on this long standing and obscure problem with ARM nfs client. I found the initial place of nfs failure. Sometimes 'ls -lR /home' command sleeps inside __rpc_execute() function and doesn't get really woken up. While everything looks like going correctly and wake_up(&task->tk_wait) is called (with rpc_clear_sleeping(task) previously done) in rpc_make_runnable() function, and the address of wait queue ( &task->tk_wait ) used in __wait_event(task->tk_wait, !RPC_IS_SLEEPING(task)) and wake_up(&task->tk_wait) is the same. But for some reason task doesn't get woken up !!!
I'm not shure which layer of kernel code could be responsible for this, and where to look in now. Help, please !!!
My current kernel is 2.4.21-pre6 based with patches from 2.4.19-rmk7 applied (well partially, except ide and pci cause i don't have them, board is mostly brutus). I'm using HARD mounted nfs volume now !!! The tail of dmesg is following.
NFS: lookup(LC_MESSAGES/kmid.mo)
NFS: lookup nfs_cached_lookup()
NFS: lookup nfs_fhget()
NFS: nfs_fhget(LC_MESSAGES/kmid.mo fileid=3227729)
NFS: refresh_inode(9/3227729 ct=1 info=0x6)
NFS: __nfs_fhget(9/3227729 ct=1)
NFS: lookup nfs_renew_times()
NFS: lookup out:
NFS: revalidating (9/3227729/3227729 count=1)
NFS: lock_kernel()
NFS: exit while (NFS_REVALIDATING(inode)) NFS call getattr
RPC: 3871 new task procpid 171 RPC: 3871 looking up UNIX cred RPC: 3871 rpc_execute flgs 0 RPC: 3871 deleting timer RPC: 3871 call_start nfs3 proc 1 (sync) RPC: 3871 deleting timer RPC: 3871 call_reserve RPC: 3871 reserved req c0e0f074 xid 00032f1d RPC: 3871 deleting timer RPC: 3871 call_reserveresult (status 0) RPC: 3871 deleting timer RPC: 3871 call_allocate (status 0) RPC: allocated buffer c0dd1000 RPC: 3871 deleting timer RPC: 3871 call_encode (status 0) RPC: 3871 marshaling UNIX cred c8f3a0a0 RPC: 3871 deleting timer RPC: 3871 call_bind xprt c0e0f000 is connected RPC: 3871 deleting timer RPC: 3871 call_transmit (status 0) RPC: 3871 xprt_transmit(32f1d) RPC: 3871 xprt_cwnd_limited cong = 0 cwnd = 512 RPC: xprt_sendmsg(0) = 104 RPC: 3871 xmit complete RPC: 3871 sleep_on(queue "xprt_pending" time 1248461) RPC: 3871 added to queue c0e0f058 "xprt_pending" RPC: 3871 setting alarm for 4 ms RPC: wake_up_next(c0e0f04c "xprt_resend") RPC: wake_up_next(c0e0f040 "xprt_sending") RPC: 3871 sync task going to sleep on c0e83e70 RPC: udp_data_ready... RPC: udp_data_ready client c0e0f000 RPC: 3871 received reply RPC: cong 256, cwnd was 512, now 512 RPC: wake_up_next(c0e0f04c "xprt_resend") RPC: wake_up_next(c0e0f040 "xprt_sending") RPC: 3871 has input (112 bytes) RPC: 3871 __rpc_wake_up_task (now 1248462 inh 0) RPC: 3871 disabling timer RPC: 3871 removed from queue c0e0f058 "xprt_pending" RPC: 3871 sync task was woken up on c0e83e70 in rpc_make_runnable() !!! RPC: __rpc_wake_up_task done NFS: dentry_delete(hu/LC_MESSAGES, 0) NFS: dentry_delete(il/LC_MESSAGES, 0) NFS: dentry_delete(locale/br, 0) NFS: dentry_delete(locale/ca, 0) NFS: dentry_delete(locale/cs, 0) NFS: dentry_delete(locale/da, 0) NFS: dentry_delete(share/ghostscript, 0) NFS: dentry_delete(licq/qt-gui, 0) NFS: dentry_delete(locale/de, 0) NFS: dentry_delete(is/LC_MESSAGES, 0) NFS: dentry_delete(it/LC_MESSAGES, 0) NFS: dentry_delete(ja/LC_MESSAGES, 0) NFS: dentry_delete(ko/LC_MESSAGES, 0) NFS: dentry_delete(mk/LC_MESSAGES, 0) NFS: dentry_delete(nl/LC_MESSAGES, 0) RPC: 656 running timer RPC: 656 timeout (default timer) RPC: 656 __rpc_wake_up_task (now 1256944 inh 0) RPC: 656 disabling timer RPC: 656 removed from queue c0138a1c "nfs_flushd" RPC: 656 added to queue c013e6e8 "schedq" RPC: __rpc_wake_up_task done RPC: switch to rpciod RPC: rpc_schedule enter RPC: 656 removed from queue c013e6e8 "schedq" RPC: 656 rpc_execute flgs 81 RPC: 656 deleting timer NFS: 656 flushd starting NFS: 656 flushd back to sleep RPC: 656 sleep_on(queue "nfs_flushd" time 1256944) RPC: 656 added to queue c0138a1c "nfs_flushd" RPC: 656 setting alarm for 30000 ms RPC: rpc_schedule leave RPC: rpciod back to sleep RPC: 2 running timer RPC: 2 timeout (default timer) RPC: 2 __rpc_wake_up_task (now 1278435 inh 0) RPC: 2 disabling timer RPC: 2 removed from queue c0138a1c "nfs_flushd" RPC: 2 added to queue c013e6e8 "schedq" RPC: __rpc_wake_up_task done RPC: switch to rpciod RPC: rpc_schedule enter RPC: 2 removed from queue c013e6e8 "schedq" RPC: 2 rpc_execute flgs 81 RPC: 2 deleting timer NFS: 2 flushd starting NFS: 2 flushd back to sleep RPC: 2 sleep_on(queue "nfs_flushd" time 1278435) RPC: 2 added to queue c0138a1c "nfs_flushd" RPC: 2 setting alarm for 30000 ms RPC: rpc_schedule leave RPC: rpciod back to sleep
-pid- proc flgs status -client- -prog- --rqstp- -timeout -rpcwait -action- --exit--
03871 0001 0000 000000 c8f5fa80 100003 c0e0f074 00000000 <NULL> c00f17ac 0
00656 0000 0081 -00110 c8f5fa80 100003 0 00030000 nfs_flushd c0066c08 c0066d40
00002 0000 0081 -00110 c0e15d80 100003 0 00030000 nfs_flushd c0066c08 c0066d40
Cheers, Vladimir.
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Did you try the patch I sent you last week? (appended below)
Cheers,
Trond
include/linux/sunrpc/sched.h renamed from include/linux/sunrpc/sched.h.orig +6 -1
@@ -128,7 +128,12 @@#define RPC_IS_RUNNING (t) (test_bit(RPC_TASK_RUNNING, &(t)->tk_runstate))#define rpc_set_running (t) (set_bit(RPC_TASK_RUNNING, &(t)->tk_runstate)) -#define rpc_clear_running (t) (clear_bit(RPC_TASK_RUNNING, &(t)->tk_runstate)) +#define rpc_clear_running (t) \ + do { \ + smp_mb__before_clear_bit(); \ + clear_bit(RPC_TASK_RUNNING, &(t)->tk_runstate); \ + smp_mb__after_clear_bit(); \ + } while(0)#define rpc_set_sleeping (t) (set_bit(RPC_TASK_SLEEPING, &(t)->tk_runstate))
include/linux/sunrpc/xprt.h renamed from include/linux/sunrpc/xprt.h.orig +6 -1
@@ -200,7 +200,12 @@#define xprt_connected (xp) (test_bit(XPRT_CONNECT, &(xp)->sockstate))#define xprt_set_connected (xp) (set_bit(XPRT_CONNECT, &(xp)->sockstate))#define xprt_test_and_set_connected (xp) (test_and_set_bit(XPRT_CONNECT, &(xp)->sockstate)) -#define xprt_clear_connected (xp) (clear_bit(XPRT_CONNECT, &(xp)->sockstate)) +#define xprt_clear_connected (xp) \ + do { \ + smp_mb__before_clear_bit(); \ + clear_bit(XPRT_CONNECT, &(xp)->sockstate); \ + smp_mb__after_clear_bit(); \ + } while(0)#endif /* __KERNEL__*/
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 5 lines · Trond Myklebust
Did you try the patch I sent you last week? (appended below)
Cheers,
Trond
Yes I do, Trond.
It doesn't help, and probably shouldn't, because it's UP not SMP system.
Cheers, Vladimir.
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
" " == Vladimir Serov <[email protected]> writes:
> Yes I do, Trond. It doesn't help, and probably shouldn't, > because it's UP not SMP system.
Then I haven't a clue as to why the PPC case should differ from the normal i386 case.
Have you been able to capture a trace of the __rpc_wake_up_task() call that fails? So far I've only seen traces of what happens afterwards.
Cheers,
Trond
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
In reply to Vladimir SerovQuoted 4 lines · Vladimir Serov
My current kernel is 2.4.21-pre6 based with patches from 2.4.19-rmk7 applied (well partially, except ide and pci cause i don't have them, board is mostly brutus). I'm using HARD mounted nfs volume now !!! The tail of dmesg is following.
Looking back on stuff which happened a long time ago, there's a possibility that there's an ordering issue with set_current_state.
Please note that this is affects _all_ 2.4 architectures.
I think this was discussed about 6 months ago, so I'm surprised this hasn't made it into the 2.4.2x kernel (or no one else has seen the problem.)
Please note that since I don't track 2.4 kernels currently, I've no idea whether 2.4.21-pre/rc has this fix. (This means if Marcelo drops or ignores the fix, it won't get re-sent.) Certainly gcc 3 requires this patch. I've not heard of gcc 2.95.x tripping over this problem though.
The problem area is:
#define __set_task_state(tsk, state_value) \
do { (tsk)->state = (state_value); } while (0)
#ifdef CONFIG_SMP
#define set_task_state(tsk, state_value) \
set_mb((tsk)->state, (state_value))
#else
#define set_task_state(tsk, state_value) \
__set_task_state((tsk), (state_value))#endif
#define __set_current_state(state_value) \
do { current->state = (state_value); } while (0)
#ifdef CONFIG_SMP
#define set_current_state(state_value) \
set_mb(current->state, (state_value))#else
#define set_current_state(state_value) \
__set_current_state(state_value)
#endif
As they currently stand, there is no guarantee that the assignment to "->state" occurs before the condition in wait_event is processed.
The attached patch should fix your problem. It should be applied to 2.4.2x. All architectures which do not provide set_mb() need to be fixed.
include/linux/sched.h +0 -10
@@ -94,23 +94,13 @@#define __set_task_state (tsk, state_value) \ do { (tsk)->state = (state_value); } while (0) -#ifdef CONFIG_SMP #define set_task_state (tsk, state_value) \ set_mb((tsk)->state, (state_value)) -#else -#define set_task_state (tsk, state_value) \ - __set_task_state((tsk), (state_value)) -#endif #define __set_current_state (state_value) \ do { current->state = (state_value); } while (0) -#ifdef CONFIG_SMP #define set_current_state (state_value) \ set_mb(current->state, (state_value)) -#else -#define set_current_state (state_value) \ - __set_current_state(state_value) -#endif /* * Scheduling policies
include/asm-arm/system.h +2 -0
@@ -46,6 +46,8 @@#define mb () __asm__ __volatile__ ("" : : : "memory")#define rmb () mb()#define wmb () mb() +#define set_mb (var, value) do { var = value; mb(); } while (0) +#define set_wmb (var, value) do { var = value; wmb(); } while (0)#define nop () __asm__ __volatile__("mov\tr0,r0\t@ nop\n\t");#define prepare_to_switch () do { } while(0)
Signature · 2 lines
Russell King ([email protected]) The developer of ARM Linux http://www.arm.linux.org.uk/personal/aboutme.html
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 6 lines · Russell King
Quoted 4 lines · Vladimir Serov
My current kernel is 2.4.21-pre6 based with patches from 2.4.19-rmk7 applied (well partially, except ide and pci cause i don't have them, board is mostly brutus). I'm using HARD mounted nfs volume now !!! The tail of dmesg is following.
Quoted 8 lines
Looking back on stuff which happened a long time ago, there's a possibility that there's an ordering issue with
set_current_state.Please note that this is affects _all_ 2.4 architectures.
I think this was discussed about 6 months ago, so I'm surprised this hasn't made it into the 2.4.2x kernel (or no one else has seen the problem.)
Yes, it was first discovered 7 months ago, but it seems Marcelo didn't merge the fix:
Quoted 4 lines
Date: Fri, 18 Oct 2002 23:00:58 -0400 (EDT)
From: Nicolas Pitre <[email protected]>
To: Marcelo Tosatti <[email protected]>
Subject: [PATCH]set_task_state()UP memory barriers
Nicolas included a more complete fix which updates all 2.4 architectures. Nico - could you re-send your fix please?
Signature · 2 lines
Russell King ([email protected]) The developer of ARM Linux http://www.arm.linux.org.uk/personal/aboutme.html
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
Quoted 19 lines · Russell King
Quoted 6 lines · Russell King
Quoted 4 lines · Vladimir Serov
My current kernel is 2.4.21-pre6 based with patches from 2.4.19-rmk7 applied (well partially, except ide and pci cause i don't have them, board is mostly brutus). I'm using HARD mounted nfs volume now !!! The tail of dmesg is following.
Quoted 8 lines
Looking back on stuff which happened a long time ago, there's a possibility that there's an ordering issue with
set_current_state.Please note that this is affects _all_ 2.4 architectures.
I think this was discussed about 6 months ago, so I'm surprised this hasn't made it into the 2.4.2x kernel (or no one else has seen the problem.)
Yes, it was first discovered 7 months ago, but it seems Marcelo didn't merge the fix:
Quoted 7 lines
Quoted 4 lines
Date: Fri, 18 Oct 2002 23:00:58 -0400 (EDT)
From: Nicolas Pitre <[email protected]>
To: Marcelo Tosatti <[email protected]>
Subject: [PATCH]set_task_state()UP memory barriersNicolas included a more complete fix which updates all 2.4 architectures. Nico - could you re-send your fix please?
Here it is, again.
---------- Forwarded message ----------
Quoted 1 line
From [email protected] Wed May 21 10:55:10 2003
Date: Fri, 18 Oct 2002 23:00:58 -0400 (EDT)
From: Nicolas Pitre <[email protected]>
To: Marcelo Tosatti <[email protected]>
Subject: [PATCH] set_task_state() UP memory barriers
This fixes the UP set_task_state and set_current_state to ensure that we don't re-order loads around the store for setting task->state.
The patch below has just been merged into 2.5 by Linus but 2.4 needs this as well, especially if gcc-3.2.x is used to compile the kernel.
include/asm-arm/system.h +2 -0
@@ -39,6 +39,8 @@#define mb () __asm__ __volatile__ ("" : : : "memory")#define rmb () mb()#define wmb () mb() +#define set_mb (var, value) do { var = value; mb(); } while (0) +#define set_wmb (var, value) do { var = value; wmb(); } while (0)#define nop () __asm__ __volatile__("mov\tr0,r0\t@ nop\n\t");#define prepare_to_switch () do { } while(0)
include/asm-cris/system.h +2 -0
@@ -150,6 +150,8 @@#define mb () __asm__ __volatile__ ("" : : : "memory")#define rmb () mb()#define wmb () mb() +#define set_mb (var, value) do { var = value; mb(); } while (0) +#define set_wmb (var, value) do { var = value; wmb(); } while (0)#ifdef CONFIG_SMP #define smp_mb () mb()
include/asm-i386/system.h +2 -1
@@ -305,13 +305,14 @@#define smp_mb () mb()#define smp_rmb () rmb()#define smp_wmb () wmb() +#define set_mb (var, value) do { xchg(&var, value); } while (0)#else #define smp_mb () barrier()#define smp_rmb () barrier()#define smp_wmb () barrier() +#define set_mb (var, value) do { var = value; barrier(); } while (0)#endif -#define set_mb (var, value) do { xchg(&var, value); } while (0)#define set_wmb (var, value) do { var = value; wmb(); } while (0)/* interrupt control.. */
Only in linux/include/asm-i386: system.h.orig
include/asm-m68k/system.h +1 -1
@@ -82,7 +82,7 @@#define mb () barrier()#define rmb () barrier()#define wmb () barrier() -#define set_mb (var, value) do { xchg(&var, value); } while (0) +#define set_mb (var, value) do { var = value; mb(); } while (0)#define set_wmb (var, value) do { var = value; wmb(); } while (0)#define smp_mb () barrier()
Only in linux/include/asm-parisc: system.h.orig
include/asm-sh/system.h +1 -1
@@ -100,7 +100,7 @@#define smp_wmb () barrier()#endif -#define set_mb (var, value) do { xchg(&var, value); } while (0) +#define set_mb (var, value) do { var = value; mb(); } while (0)#define set_wmb (var, value) do { var = value; wmb(); } while (0)/* Interrupt Control */
Only in linux/include/asm-sh: system.h.orig
include/linux/sched.h +0 -10
@@ -94,23 +94,13 @@#define __set_task_state (tsk, state_value) \ do { (tsk)->state = (state_value); } while (0) -#ifdef CONFIG_SMP #define set_task_state (tsk, state_value) \ set_mb((tsk)->state, (state_value)) -#else -#define set_task_state (tsk, state_value) \ - __set_task_state((tsk), (state_value)) -#endif #define __set_current_state (state_value) \ do { current->state = (state_value); } while (0) -#ifdef CONFIG_SMP #define set_current_state (state_value) \ set_mb(current->state, (state_value)) -#else -#define set_current_state (state_value) \ - __set_current_state(state_value) -#endif /* * Scheduling policies
Re: [BUG] nfs client stuck in D state in linux 2.4.17 - 2.4.21-pre5
In reply to Russell KingQuoted 6 lines · Russell King
Looking back on stuff which happened a long time ago, there's a possibility that there's an ordering issue with
set_current_state.Please note that this is affects _all_ 2.4 architectures.
..........................
Quoted 6 lines
The attached patch should fix your problem. It should be applied to 2.4.2x. All architectures which do not provide
set_mb()need to be fixed.
Thanks a lot !!! It works !!!
With best regards, Vladimir.