Tracking down a nasty delegation return bug

I've been fixing up a refcnt bug I found in recall_read_delegations(). One of the things I found out while in Austin was how to unit test those changes. We need a NFSv4.0 and a NFSv4.1 client both reading a file from a NFSv4.1 server. Note that we can't have a pNFS server, due to we do not yet support a mount option to force a 4.1 over a 4.0 mount. And we may never.

Anyway, you have two clients with a read delegation and force a recall by touching the files from another client.

I know it is a good test case because the server consistently crashes:

panic[cpu0]/thread=ffffff02d457db40: kernel heap corruption detected

ffffff001054de90 genunix:kmem_error+4a9 ()
ffffff001054deb0 genunix:kmem_free+d0 ()
ffffff001054df30 nfssrv:recall_read_delegations+8e8 ()
ffffff001054df90 nfssrv:deleg_rd_setattr+45 ()
ffffff001054e000 genunix:vnext_setattr+84 ()
ffffff001054e060 nfssrv:deleg_rd_setattr+66 ()
ffffff001054e0e0 genunix:vhead_setattr+9f ()
ffffff001054e140 genunix:fop_setattr+ad ()

Firefox rules! My UPS just failed and I thought I lost all of this. Yeah Firefox for saving the day!

I added DTrace probes, printf() statements when the probes failed to fire, and finally delays in the code. I couldn't see anything. I finally decided to remove all of that code and worked on cleaning the original code up. There was a rfs4_file_t pointer (fp), array of pointers (fpa), and last active pointer (fap). I was getting confused.

I fixed all that and while the panic was still occurring, the code was easier to read. I finally started adding some ASSERTs and nailed down the problem!

If we look at the original code:

 89         /\*
 90          \* Is there more than one file structure for this vp?
 91          \* Get the vsd for each instance of the server, if it exists.
 92          \*/
 93         fpa = kmem_zalloc((sizeof (rfs4_file_t \*) \* nsi_count), KM_SLEEP);
 94         DTRACE_NFSV4_1(rrd__i__fpa_alloc, int, nsi_count);
 95 
 96         fpa[0] = fp;
 97         cnt = 1;
 98         mutex_enter(&vp->v_lock);
 99         for (instp = list_head(&nsi_head); instp != NULL;
100             instp = list_next(&nsi_head, &instp->nsi_list)) {
101                 fpa[cnt] = (rfs4_file_t \*)vsd_get(vp, instp->vkey);
102                 if (fpa[cnt] && (fpa[cnt] != fp))
103                         cnt++;
104         }
105         mutex_exit(&vp->v_lock);

I said that before 101, it should be the case that cnt is less than nsi_count. I added an ASSERT and it triggered right away. I looked back at the code and while I still thought the ASSERT was valid, I saw why it could trigger in a good code path. Consider a case where the number of items in the list is greater than nsi_count. Then consider that we immediately fill in the remaining items in fpa, leaving some items in the list. We then read an item, but we don't mean to store it.

That is where the bug actually comes in I believe in the author's mind. Either there never is more than nsi_count entries in the list or not considering there can be more valid ones. Another point here is that there is no way to guarantee that the first item returned in the list is fp.

My fix is this:

103         for (instp = list_head(&nsi_head); instp != NULL;
104             instp = list_next(&nsi_head, &instp->nsi_list)) {
105                 rfs4_file_t     \*temp;
106 
107                 temp = (rfs4_file_t \*)vsd_get(vp, instp->vkey);
108                 if (temp && (temp != fp)) {
109                         ASSERT(cnt < nsi_count);
110                         fpa[cnt++] = temp;
111                 }
112         }

It works as a great defensive fix, but I'm concerned it misses the bigger issue of we should either count the items first in the list for the allocation or we should determine why we have more entries than we expect. I'll have to confer with my colleague once he gets back from vacation...


Originally posted on Kool Aid Served Daily
Copyright (C) 2009, Kool Aid Served Daily
Comments:

Post a Comment:
  • HTML Syntax: NOT allowed
About

tdh

Search

Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today