Bug 842435

Summary: NFSv4 Handle a bad or revoked delegation
Product: Red Hat Enterprise Linux 6 Reporter: Andy Adamson <andros>
Component: kernelAssignee: Steve Dickson <steved>
Status: CLOSED ERRATA QA Contact: Jian Li <jiali>
Severity: high Docs Contact:
Priority: urgent    
Version: 6.4CC: acase, bfields, cww, dhoward, dwysocha, eguan, fhrbata, jiali, jlayton, msvoboda, nmurray, rwheeler, steved
Target Milestone: rcKeywords: ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: kernel-2.6.32-315.el6 Doc Type: Bug Fix
Doc Text:
When an NFSv4 client received a read delegation, a race between the OPEN and DELEGRETURN operation could occur. If the DELEGRETURN operation was processed first, the NFSv4 client treated the delegation returned by the following OPEN as a new delegation. Also, the NFSv4 client did not correctly handle errors caused by requests that used a bad or revoked delegation state ID. As a result, applications running on the client could receive spurious EIO errors. This update applies a series of patches that fix the NFSv4 code so an NFSv4 client recovers correctly in the described situations instead of returning errors to applications.
 Story Points: ---
Clone Of:
: 967051 (view as bug list) Environment:
Last Closed: 2013-02-21 06:42:48 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 846840, 967051    
Attachments:
Description Flags
back port of the 8 required patches to the 2.6.32-285 kernel none

Description Andy Adamson 2012-07-23 20:53:39 UTC 
Created attachment 599861 [details]
back port of the 8 required patches to the 2.6.32-285 kernel

Description of problem: 
The NFSv4 client does not order OPEN and DELEGRETURN,
and so the two operations can race. When that happens, it looks to the
client as if it has received a new delegation, when in fact it is the
same one that is being delegareturned.  

Another instance of this problem occurs
when a delegation stateid is bad (NFS4ERR_BAD_STATEID) or revoked (NFS4ERR_DELEG_REVOKED for NFSv4.1) where the client returns EIO to the application. 


Version-Release number of selected component (if applicable): 

RHEL 6.1/2/3/4
Tested against kernel 2.6.32-285.

How reproducible:
100%


Steps to Reproduce:
1.Use the pynfs NFSv4.1 server ops_config infrastructure to inject an NFS4ERR_BAD_STATEID on READ.
2. cat a file. The pynfs server hands out READ delegations on open.
3.
  
Actual results:

The pynfs server ops_config test not only returns NFS4ERR_BAD_STATEID on the first read, but also removes the stateid from the pynfs server state cache. The
READ is retried several times, each READ returns an NFS4ERR_BAD_STATEID, and
EIO is returned to the 'cat' command.


Expected results:

The NFS4ERR_BAD_STATEID should be handled, a new OPEN should be sent, and the 
READ retried with a new stateid.


Additional info:

This patch fixes the bug.

From a1d0b5eebc4fd6e0edb02688b35f17f67f42aea5 Mon Sep 17 00:00:00 2001
From: Trond Myklebust <Trond.Myklebust>
Date: Mon, 5 Mar 2012 19:56:44 -0500
Subject: [PATCH 1/1] NFS: Properly handle the case where the delegation is revoked

If we know that the delegation stateid is bad or revoked, we need to
remove that delegation as soon as possible, and then mark all the
stateids that relied on that delegation for recovery. We cannot use
the delegation as part of the recovery process.

Also note that NFSv4.1 uses a different error code (NFS4ERR_DELEG_REVOKED)
to indicate that the delegation was revoked.

Finally, ensure that setlk() and setattr() can both recover safely from
a revoked delegation.

Signed-off-by: Trond Myklebust <Trond.Myklebust>
Cc: stable.org
---


I have back ported the following patches required by the above patch and tested
the resultant 2.6.32-285 patched kernel to verify that the bug is fixed.

Attached is a tar ball of the ported patch set which includes

1) A beginning patch 0001-ANDROS-fix-br_private.h-for-2.6.32-285.patch, required for compiling the 2.6.32-285 source (with my .config)

2) A final patch 0009-BACKPORT-remove-rcu_dereference_raw-define-from-rcul.patch
which removes a duplicate declaration that I think is a result of past back ports.


8 Patches required:

From 632ee200130899252508c478ad0e808222573fbc Mon Sep 17 00:00:00 2001
From: Paul E. McKenney <paulmck.ibm.com>
Date: Mon, 22 Feb 2010 17:04:45 -0800
Subject: [PATCH 1/1] rcu: Introduce lockdep-based checking to RCU read-side primitives

Inspection is proving insufficient to catch all RCU misuses,
which is understandable given that rcu_dereference() might be
protected by any of four different flavors of RCU (RCU, RCU-bh,
RCU-sched, and SRCU), and might also/instead be protected by any
of a number of locking primitives. It is therefore time to
enlist the aid of lockdep.

This set of patches is inspired by earlier work by Peter
Zijlstra and Thomas Gleixner, and takes the following approach:

o       Set up separate lockdep classes for RCU, RCU-bh, and RCU-sched.

o       Set up separate lockdep classes for each instance of SRCU.

o       Create primitives that check for being in an RCU read-side
        critical section.  These return exact answers if lockdep is
        fully enabled, but if unsure, report being in an RCU read-side
        critical section.  (We want to avoid false positives!)
        The primitives are:

        For RCU: rcu_read_lock_held(void)

        For RCU-bh: rcu_read_lock_bh_held(void)

        For RCU-sched: rcu_read_lock_sched_held(void)

        For SRCU: srcu_read_lock_held(struct srcu_struct *sp)

o       Add rcu_dereference_check(), which takes a second argument
        in which one places a boolean expression based on the above
        primitives and/or lockdep_is_held().

o       A new kernel configuration parameter, CONFIG_PROVE_RCU, enables
        rcu_dereference_check().  This depends on CONFIG_PROVE_LOCKING,
        and should be quite helpful during the transition period while
        CONFIG_PROVE_RCU-unaware patches are in flight.

The existing rcu_dereference() primitive does no checking, but
upcoming patches will change that.

Signed-off-by: Paul E. McKenney <paulmck.ibm.com>
Cc: laijs.com
Cc: dipankar.com
Cc: mathieu.desnoyers
Cc: josh
Cc: dvhltc.com
Cc: niv.com
Cc: peterz
Cc: rostedt
Cc: Valdis.Kletnieks
Cc: dhowells
LKML-Reference: <1266887105-1528-1-git-send-email-paulmck.ibm.com>
Signed-off-by: Ingo Molnar <mingo>

--------


From c26d34a5858f96a564c45048bf5f09319d2abad1 Mon Sep 17 00:00:00 2001
From: Paul E. McKenney <paulmck.ibm.com>
Date: Mon, 22 Feb 2010 17:04:46 -0800
Subject: [PATCH 1/1] rcu: Add lockdep-enabled variants of rcu_dereference()

Make rcu_dereference() check for being in an RCU read-side
critical section, and create rcu_dereference_bh(),
rcu_dereference_sched(), and srcu_dereference() to check for the
other flavors of RCU.  Also create rcu_dereference_raw() to
avoid checking, and make rcu_dereference_check() use
rcu_dereference_raw().

Acked-by: Eric Dumazet <eric.dumazet>
Signed-off-by: Paul E. McKenney <paulmck.ibm.com>
Cc: laijs.com
Cc: dipankar.com
Cc: mathieu.desnoyers
Cc: josh
Cc: dvhltc.com
Cc: niv.com
Cc: peterz
Cc: rostedt
Cc: Valdis.Kletnieks
Cc: dhowells
LKML-Reference: <1266887105-1528-2-git-send-email-paulmck.ibm.com>
Signed-off-by: Ingo Molnar <mingo>

-----------


From b62730baea32f86fe91a7930e4b7ee8d82778b79 Mon Sep 17 00:00:00 2001
From: Paul E. McKenney <paulmck.ibm.com>
Date: Fri, 9 Apr 2010 15:39:10 -0700
Subject: [PATCH 1/1] rcu: Add rcu_access_pointer and rcu_dereference_protected

This patch adds variants of rcu_dereference() that handle
situations where the RCU-protected data structure cannot change,
perhaps due to our holding the update-side lock, or where the
RCU-protected pointer is only to be fetched, not dereferenced.
These are needed due to some performance concerns with using
rcu_dereference() where it is not required, aside from the need
for lockdep/sparse checking.

The new rcu_access_pointer() primitive is for the case where the
pointer is be fetch and not dereferenced.  This primitive may be
used without protection, RCU or otherwise, due to the fact that
it uses ACCESS_ONCE().

The new rcu_dereference_protected() primitive is for the case
where updates are prevented, for example, due to holding the
update-side lock.  This primitive does neither ACCESS_ONCE() nor
smp_read_barrier_depends(), so can only be used when updates are
somehow prevented.

Suggested-by: David Howells <dhowells>
Signed-off-by: Paul E. McKenney <paulmck.ibm.com>

---------


From 17d2c0a0c4d4e074f0a2a5c0090ff6d88f5e1d44 Mon Sep 17 00:00:00 2001
From: David Howells <dhowells>
Date: Sat, 1 May 2010 12:37:18 -0400
Subject: [PATCH 1/1] NFS: Fix RCU issues in the NFSv4 delegation code

Fix a number of RCU issues in the NFSv4 delegation code.

 (1) delegation->cred doesn't need to be RCU protected as it's essentially an
     invariant refcounted structure.

     By the time we get to nfs_free_delegation(), the delegation is being
     released, so no one else should be attempting to use the saved
     credentials, and they can be cleared.

     However, since the list of delegations could still be under traversal at
     this point by such as nfs_client_return_marked_delegations(), the cred
     should be released in nfs_do_free_delegation() rather than in
     nfs_free_delegation().  Simply using rcu_assign_pointer() to clear it is
     insufficient as that doesn't stop the cred from being destroyed, and nor
     does calling put_rpccred() after call_rcu(), given that the latter is
     asynchronous.

 (2) nfs_detach_delegation_locked() and nfs_inode_set_delegation() should use
     rcu_derefence_protected() because they can only be called if
     nfs_client::cl_lock is held, and that guards against anyone changing
     nfsi->delegation under it.  Furthermore, the barrier imposed by
     rcu_dereference() is superfluous, given that the spin_lock() is also a
     barrier.

 (3) nfs_detach_delegation_locked() is now passed a pointer to the nfs_client
     struct so that it can issue lockdep advice based on clp->cl_lock for (2).

 (4) nfs_inode_return_delegation_noreclaim() and nfs_inode_return_delegation()
     should use rcu_access_pointer() outside the spinlocked region as they
     merely examine the pointer and don't follow it, thus rendering unnecessary
     the need to impose a partial ordering over the one item of interest.

     These result in an RCU warning like the following:

---------


From dda4b225623f316335052828c24a16e2da313f8f Mon Sep 17 00:00:00 2001
From: Chuck Lever <chuck.lever>
Date: Fri, 24 Dec 2010 01:32:54 +0000
Subject: [PATCH 1/1] NFS: Introduce nfs_detach_delegations()

Clean up:  Refactor code that takes clp->cl_lock and calls
nfs_detach_delegations_locked() into its own function.

While we're changing the call sites, get rid of the second parameter
and the logic in nfs_detach_delegations_locked() that uses it, since
callers always set that parameter of nfs_detach_delegations_locked()
to NULL.

Signed-off-by: Chuck Lever <chuck.lever>
Signed-off-by: Trond Myklebust <Trond.Myklebust>

-----------


From d3978bb325510f0a26ebd92f211b36c5f98b2306 Mon Sep 17 00:00:00 2001
From: Chuck Lever <chuck.lever>
Date: Fri, 24 Dec 2010 01:33:04 +0000
Subject: [PATCH 1/1] NFS: Move cl_delegations to the nfs_server struct

Delegations are per-inode, not per-nfs_client.  When a server file
system is migrated, delegations on the client must be moved from the
source to the destination nfs_server.  Make it easier to manage a
mount point's delegation list across a migration event by moving the
list to the nfs_server struct.

Clean up: I added documenting comments to public functions I changed
in this patch.  For consistency I added comments to all the other
public functions in fs/nfs/delegation.c.

Signed-off-by: Chuck Lever <chuck.lever>
Signed-off-by: Trond Myklebust <Trond.Myklebust>

--------


From d3978bb325510f0a26ebd92f211b36c5f98b2306 Mon Sep 17 00:00:00 2001
From: Chuck Lever <chuck.lever>
Date: Fri, 24 Dec 2010 01:33:04 +0000
Subject: [PATCH 1/1] NFS: Move cl_delegations to the nfs_server struct

Delegations are per-inode, not per-nfs_client.  When a server file
system is migrated, delegations on the client must be moved from the
source to the destination nfs_server.  Make it easier to manage a
mount point's delegation list across a migration event by moving the
list to the nfs_server struct.

Clean up: I added documenting comments to public functions I changed
in this patch.  For consistency I added comments to all the other
public functions in fs/nfs/delegation.c.

Signed-off-by: Chuck Lever <chuck.lever>
Signed-off-by: Trond Myklebust <Trond.Myklebust>
Comment 2 RHEL Program Management 2012-07-24 12:40:23 UTC 
This request was evaluated by Red Hat Product Management for
inclusion in a Red Hat Enterprise Linux release.  Product
Management has requested further review of this request by
Red Hat Engineering, for potential inclusion in a Red Hat
Enterprise Linux release for currently deployed products.
This request is not yet committed for inclusion in a release.
Comment 4 Jian Li 2012-08-01 06:00:20 UTC 
reproducer refer to comment 0, regression nfs test is needed.
Comment 6 Jarod Wilson 2012-10-01 17:31:41 UTC 
Patch(es) available on kernel-2.6.32-315.el6
Comment 9 Jeff Layton 2012-10-12 10:06:02 UTC 
*** Bug 800681 has been marked as a duplicate of this bug. ***
Comment 10 Jian Li 2012-11-23 03:26:52 UTC 
This bug is reproduced on 2.6.32-287.el6, and verified on 2.6.32-338.el6. 

When bug is reproduced, client would send READ call looply always.  
newpynfs output:  (sequenceid is increasing..)
**snip**
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000200000001', sa_sequenceid=2342, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=False)), nfs_argop4(argop=OP_PUTFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02')), nfs_argop4(argop=OP_READ, opread=READ4args(stateid=stateid4(seqid=0, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x02'), offset=0L, count=29))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_READ (25) ***
INFO   :nfs.server:Replying.  Status NFS4ERR_BAD_STATEID (10025)
INFO   :nfs.server:COMPOUND4res(status=NFS4ERR_BAD_STATEID, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000200000001', sr_sequenceid=2342, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_READ, opread=READ4res(status=NFS4ERR_BAD_STATEID))])
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000200000001', sa_sequenceid=2343, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=False)), nfs_argop4(argop=OP_PUTFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02')), nfs_argop4(argop=OP_READ, opread=READ4args(stateid=stateid4(seqid=0, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x02'), offset=0L, count=29))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_READ (25) ***
INFO   :nfs.server:Replying.  Status NFS4ERR_BAD_STATEID (10025)
INFO   :nfs.server:COMPOUND4res(status=NFS4ERR_BAD_STATEID, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000200000001', sr_sequenceid=2343, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_READ, opread=READ4res(status=NFS4ERR_BAD_STATEID))])
**snip**

when verified, after READ call get NFS4ERR_BAD_STATEID, an 'OPEN' call is send again.
newpynfs output:
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_
sessionid='0000000100000001', sa_sequenceid=21, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=True)), nfs_argop4(argop=OP_PU
TFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\
x00\x01')), nfs_argop4(argop=OP_SAVEFH), nfs_argop4(argop=OP_OPEN, opopen=OPEN4args(seqid=0, share_access=1, share_deny=0, ow
ner=state_owner4(clientid=1L, owner='open id:\x00\x00\x00\x14#\xb8*\x8e N\xa82'), openhow=openflag4(opentype=OPEN4_NOCREATE),
 claim=open_claim4(claim=CLAIM_NULL, file='date'))), nfs_argop4(argop=OP_GETFH), nfs_argop4(argop=OP_GETATTR, opgetattr=GETAT
TR4args(attr_request=42950721818L)), nfs_argop4(argop=OP_RESTOREFH), nfs_argop4(argop=OP_GETATTR, opgetattr=GETATTR4args(attr
_request=24L))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_SAVEFH (32) ***
INFO   :nfs.server:*** OP_OPEN (18) ***
DEBUG  :nfs.server:OPEN - fh = '\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\
x00\x02'
DEBUG  :nfs.server.state:GRANTING delegation: OPEN_DELEGATE_READ
stateid4(seqid=1, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x02')
<nfs4state.DelegEntry object at 0xd2fcd0>
test print, delete delegate
INFO   :nfs.server:*** OP_GETFH (10) ***
INFO   :nfs.server:*** OP_GETATTR (9) ***
handling fattr4_type :  1
handling fattr4_change :  4
handling fattr4_size :  29
handling fattr4_fsid :  fsid4(major=3, minor=1)
handling fattr4_fileid :  2
handling fattr4_mode :  420
handling fattr4_numlinks :  1
INFO   :nfs.server:*** OP_RESTOREFH (31) ***
INFO   :nfs.server:*** OP_GETATTR (9) ***
handling fattr4_change :  1
handling fattr4_size :  1
INFO   :nfs.server:Replying.  Status NFS4_OK (0)
INFO   :nfs.server:COMPOUND4res(status=NFS4_OK, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000100000001', sr_sequenceid=21, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_SAVEFH, opsavefh=SAVEFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_OPEN, opopen=OPEN4res(status=NFS4_OK, resok4=OPEN4resok(stateid=stateid4(seqid=1, other='\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01'), cinfo=change_info4(atomic=True, before=1, after=1), rflags=0, attrset=0L, delegation=open_delegation4(delegation_type=OPEN_DELEGATE_READ, read=open_read_delegation4(stateid=stateid4(seqid=1, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x02'), recall=False, permissions=nfsace4(type=1L, flag=0, access_mask=1442215L, who='EVERYONE@')))))), nfs_resop4(resop=OP_GETFH, opgetfh=GETFH4res(status=NFS4_OK, resok4=GETFH4resok(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02'))), nfs_resop4(resop=OP_GETATTR, opgetattr=GETATTR4res(status=NFS4_OK, resok4=GETATTR4resok(obj_attributes={1: 1, 3: 4, 4: 29, 33: 420, 8: fsid4(major=3, minor=1), 35: 1, 20: 2}))), nfs_resop4(resop=OP_RESTOREFH, oprestorefh=RESTOREFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_GETATTR, opgetattr=GETATTR4res(status=NFS4_OK, resok4=GETATTR4resok(obj_attributes={3: 1, 4: 1})))])
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000100000001', sa_sequenceid=22, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=False)), nfs_argop4(argop=OP_PUTFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02')), nfs_argop4(argop=OP_READ, opread=READ4args(stateid=stateid4(seqid=0, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x02'), offset=0L, count=29))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_READ (25) ***
INFO   :nfs.server:Replying.  Status NFS4ERR_BAD_STATEID (10025)
INFO   :nfs.server:COMPOUND4res(status=NFS4ERR_BAD_STATEID, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000100000001', sr_sequenceid=22, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_READ, opread=READ4res(status=NFS4ERR_BAD_STATEID))])
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000100000001', sa_sequenceid=23, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=True)), nfs_argop4(argop=OP_PUTFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x01')), nfs_argop4(argop=OP_SAVEFH), nfs_argop4(argop=OP_OPEN, opopen=OPEN4args(seqid=0, share_access=1, share_deny=0, owner=state_owner4(clientid=1L, owner='open id:\x00\x00\x00\x14#\xb8*\x8e N\xa82'), openhow=openflag4(opentype=OPEN4_NOCREATE), claim=open_claim4(claim=CLAIM_NULL, file='date'))), nfs_argop4(argop=OP_GETFH), nfs_argop4(argop=OP_GETATTR, opgetattr=GETATTR4args(attr_request=42950721818L)), nfs_argop4(argop=OP_RESTOREFH), nfs_argop4(argop=OP_GETATTR, opgetattr=GETATTR4args(attr_request=24L))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_SAVEFH (32) ***
INFO   :nfs.server:*** OP_OPEN (18) ***
DEBUG  :nfs.server:OPEN - fh = '\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02'
DEBUG  :nfs.server.state:GRANTING delegation: OPEN_DELEGATE_READ
test print, DON'T delete delegate
INFO   :nfs.server:*** OP_GETFH (10) ***
INFO   :nfs.server:*** OP_GETATTR (9) ***
handling fattr4_type :  1
handling fattr4_change :  4
handling fattr4_size :  29
handling fattr4_fsid :  fsid4(major=3, minor=1)
handling fattr4_fileid :  2
handling fattr4_mode :  420
handling fattr4_numlinks :  1
INFO   :nfs.server:*** OP_RESTOREFH (31) ***
INFO   :nfs.server:*** OP_GETATTR (9) ***
handling fattr4_change :  1
handling fattr4_size :  1
INFO   :nfs.server:Replying.  Status NFS4_OK (0)
INFO   :nfs.server:COMPOUND4res(status=NFS4_OK, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000100000001', sr_sequenceid=23, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_SAVEFH, opsavefh=SAVEFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_OPEN, opopen=OPEN4res(status=NFS4_OK, resok4=OPEN4resok(stateid=stateid4(seqid=2, other='\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01'), cinfo=change_info4(atomic=True, before=1, after=1), rflags=0, attrset=0L, delegation=open_delegation4(delegation_type=OPEN_DELEGATE_READ, read=open_read_delegation4(stateid=stateid4(seqid=1, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x03'), recall=False, permissions=nfsace4(type=1L, flag=0, access_mask=1442215L, who='EVERYONE@')))))), nfs_resop4(resop=OP_GETFH, opgetfh=GETFH4res(status=NFS4_OK, resok4=GETFH4resok(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02'))), nfs_resop4(resop=OP_GETATTR, opgetattr=GETATTR4res(status=NFS4_OK, resok4=GETATTR4resok(obj_attributes={1: 1, 3: 4, 4: 29, 33: 420, 8: fsid4(major=3, minor=1), 35: 1, 20: 2}))), nfs_resop4(resop=OP_RESTOREFH, oprestorefh=RESTOREFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_GETATTR, opgetattr=GETATTR4res(status=NFS4_OK, resok4=GETATTR4resok(obj_attributes={3: 1, 4: 1})))])
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000100000001', sa_sequenceid=24, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=False)), nfs_argop4(argop=OP_PUTFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02')), nfs_argop4(argop=OP_ACCESS, opaccess=ACCESS4args(access=45)), nfs_argop4(argop=OP_GETATTR, opgetattr=GETATTR4args(attr_request=42950721818L))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_ACCESS (3) ***
INFO   :nfs.server:*** OP_GETATTR (9) ***
handling fattr4_type :  1
handling fattr4_change :  4
handling fattr4_size :  29
handling fattr4_fsid :  fsid4(major=3, minor=1)
handling fattr4_fileid :  2
handling fattr4_mode :  420
handling fattr4_numlinks :  1
INFO   :nfs.server:Replying.  Status NFS4_OK (0)
INFO   :nfs.server:COMPOUND4res(status=NFS4_OK, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000100000001', sr_sequenceid=24, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_ACCESS, opaccess=ACCESS4res(status=NFS4_OK, resok4=ACCESS4resok(supported=45L, access=45L))), nfs_resop4(resop=OP_GETATTR, opgetattr=GETATTR4res(status=NFS4_OK, resok4=GETATTR4resok(obj_attributes={1: 1, 3: 4, 4: 29, 33: 420, 8: fsid4(major=3, minor=1), 35: 1, 20: 2})))])
INFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000100000001', sa_sequenceid=25, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=False)), nfs_argop4(argop=OP_PUTFH, opputfh=PUTFH4args(object='\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x02')), nfs_argop4(argop=OP_READ, opread=READ4args(stateid=stateid4(seqid=0, other='\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x03'), offset=0L, count=29))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:*** OP_PUTFH (22) ***
INFO   :nfs.server:*** OP_READ (25) ***
INFO   :nfs.server:Replying.  Status NFS4_OK (0)
INFO   :nfs.server:COMPOUND4res(status=NFS4_OK, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000100000001', sr_sequenceid=25, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0))), nfs_resop4(resop=OP_PUTFH, opputfh=PUTFH4res(status=NFS4_OK)), nfs_resop4(resop=OP_READ, opread=READ4res(status=NFS4_OK, resok4=READ4resok(eof=True, data='Thu Nov 22 22:17:24 EST 2012\n')))])
^[[A^[[A^[[A^[[A^[[A^[[A^[[A^[[A^[[A^[[A^[[B^[[B^[[B^[[B^[[BINFO   :nfs.server:****************************************
INFO   :nfs.server:Handling COMPOUND
INFO   :nfs.server:COMPOUND4args(tag='', minorversion=1, argarray=[nfs_argop4(argop=OP_SEQUENCE, opsequence=SEQUENCE4args(sa_sessionid='0000000000000001', sa_sequenceid=6, sa_slotid=0, sa_highest_slotid=0, sa_cachethis=False))])
INFO   :nfs.server:*** OP_SEQUENCE (53) ***
INFO   :nfs.server:Replying.  Status NFS4_OK (0)
INFO   :nfs.server:COMPOUND4res(status=NFS4_OK, tag='', resarray=[nfs_resop4(resop=OP_SEQUENCE, opsequence=SEQUENCE4res(sr_status=NFS4_OK, sr_resok4=SEQUENCE4resok(sr_sessionid='0000000000000001', sr_sequenceid=6, sr_slotid=0, sr_highest_slotid=0, sr_target_highest_slotid=8, sr_status_flags=0)))])
Comment 11 Jian Li 2012-11-23 03:28:26 UTC 
newpynfs modification for fault-injection:

diff --git a/nfs4.1/nfs4commoncode.py b/nfs4.1/nfs4commoncode.py
index 317f04c..2a961da 100644
--- a/nfs4.1/nfs4commoncode.py
+++ b/nfs4.1/nfs4commoncode.py
@@ -31,6 +31,7 @@ code_str = '''\
 def %(encode_status)s_by_name(name, status, *args, **kwargs):
     """ returns %(nfs_resop4)s(OP_NAME, opname=NAME4res(status, *args)) """
     tag = kwargs.pop("msg", None)
+    tag = None
     name_l = name.lower()
     name_u = name.upper()
     try:
diff --git a/nfs4.1/nfs4server.py b/nfs4.1/nfs4server.py
index b279292..69d9681 100755
--- a/nfs4.1/nfs4server.py
+++ b/nfs4.1/nfs4server.py
@@ -508,11 +508,13 @@ class Slot(object):
 
     # STUB - for client, need to track slot usage
 
+
 ##################################################
 # The primary class - it is excessively long     #
 ##################################################
 
 class NFS4Server(rpc.Server):
+    TEST_ONCE = 1
     """Implement a nfsv4.1 server."""
 
     # As the only per-server attribute, lease_time is handled specially
@@ -1327,6 +1329,19 @@ class NFS4Server(rpc.Server):
             print "+++ client(id=%i).state =" %  env.session.client.clientid
             print env.session.client.state
         res = OPEN4resok(sid, cinfo, flags, bitmask, deleg)
+        if deleg.switch and (NFS4Server.TEST_ONCE == 1):
+            tmpstateid = deleg.switch.stateid
+            print tmpstateid
+            tmpstate = env.session.client.state[tmpstateid.other] 
+            print tmpstate
+            if tmpstate :
+                tmpstate.delete()
+            NFS4Server.TEST_ONCE = 0
+            print "test print, delete delegate"
+        else:
+            NFS4Server.TEST_ONCE = 1
+            print "test print, DON'T delete delegate"
+
         return encode_status(NFS4_OK, res)
 
     def open_claim_null(self, arg, env):
Comment 14 Jian Li 2012-11-23 04:06:10 UTC 
Hi bruce, 
To this patch, problem about delegation is resolved, could I verify this bug?
Comment 18 errata-xmlrpc 2013-02-21 06:42:48 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHSA-2013-0496.html