Re: commit c7314d74fcb0

[Al Viro <viro@ZenIV.linux.org.uk>]

On Sun, Jan 19, 2014 at 09:50:51PM +0100, Arnaud Ebalard wrote:
> Hi Al,
> 
> While doing md5sum on files available on a NFSv3 share, the following
> came up on the NAS (an ARM-based ReadyNAS 102) acting as NFS server and
> running 3.13.0-rc8:
> 
> [ 3832.280073] Unable to handle kernel NULL pointer dereference at virtual address 00000000
> [ 3832.288188] pgd = c0004000
> [ 3832.290909] [00000000] *pgd=00000000
> [ 3832.294505] Internal error: Oops: 17 [#1] ARM
> [ 3832.298868] Modules linked in:
> [ 3832.301942] CPU: 0 PID: 359 Comm: kworker/0:1 Not tainted 3.13.0-rc8.rn102-00076-g7d0d46da750a-dirty #62
> [ 3832.311452] Workqueue: events delayed_fput
> [ 3832.315565] task: df88d340 ti: df940000 task.ti: df940000
> [ 3832.320973] PC is at __fput+0x24/0x1f0
> [ 3832.324729] LR is at __fput+0x1c/0x1f0
> [ 3832.328485] pc : [<c008b8c8>]    lr : [<c008b8c0>]    psr: 60000013
> [ 3832.328485] sp : df941ed0  ip : c07726c0  fp : 00000009
> [ 3832.339981] r10: 00000000  r9 : 00000000  r8 : 00000000
> [ 3832.345214] r7 : 00000000  r6 : c152b900  r5 : 00000000  r4 : 00000000
> [ 3832.351751] r3 : 0000021d  r2 : 00000000  r1 : c152be40  r0 : 00000000
> [ 3832.358290] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM Segment kernel
> [ 3832.365611] Control: 10c5387d  Table: 1eaa8019  DAC: 00000015
> [ 3832.371366] Process kworker/0:1 (pid: 359, stack limit = 0xdf940238)
> [ 3832.377729] Stack: (0xdf941ed0 to 0xdf942000)
> [ 3832.382095] 1ec0:                                     00000000 00000000 00000000 c152be40
> [ 3832.390289] 1ee0: c077569c c07726c0 df940000 c0fb0300 00000000 00000000 00000009 c008bac0
> [ 3832.398482] 1f00: df90ff80 c002d6cc c0772ff0 df940000 df941f3c c0553fa8 df88d340 df90ff80
> [ 3832.406676] 1f20: c07726c0 c07726d0 df940000 df90ff98 c07a5b55 00000001 00000009 c002dc98
> [ 3832.414869] 1f40: df941f6c c0553fa8 df88d340 00000000 df913480 df90ff80 c002db84 00000000
> [ 3832.423063] 1f60: 00000000 00000000 00000000 c0032848 d3effdfa 00000000 eff1757f df90ff80
> [ 3832.431256] 1f80: 00000000 df941f84 df941f84 00000000 df941f90 df941f90 df941fac df913480
> [ 3832.439449] 1fa0: c003278c 00000000 00000000 c000e218 00000000 00000000 00000000 00000000
> [ 3832.447642] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> [ 3832.455836] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 f727f277 47f34ef7
> [ 3832.464036] [<c008b8c8>] (__fput+0x24/0x1f0) from [<c008bac0>] (delayed_fput+0x2c/0x3c)
> [ 3832.472069] [<c008bac0>] (delayed_fput+0x2c/0x3c) from [<c002d6cc>] (process_one_work+0xf4/0x32c)
> [ 3832.480963] [<c002d6cc>] (process_one_work+0xf4/0x32c) from [<c002dc98>] (worker_thread+0x114/0x34c)
> [ 3832.490120] [<c002dc98>] (worker_thread+0x114/0x34c) from [<c0032848>] (kthread+0xbc/0xd8)
> [ 3832.498407] [<c0032848>] (kthread+0xbc/0xd8) from [<c000e218>] (ret_from_fork+0x14/0x3c)
> [ 3832.506514] Code: e5904010 eb132240 e5965010 e5963020 (e1d520b0) 
> [ 3832.512633] ---[ end trace a00affa6c4ade951 ]---
> [ 3832.517258] Kernel panic - not syncing: Fatal exception
> 
> I took a quick look at what is at __fput+0x24 and I think the issue
> happens in the inlined fsnotify_close() at the beginning of __fput():
> 
> static void __fput(struct file *file)
> {
> 	struct dentry *dentry = file->f_path.dentry;
> 	struct vfsmount *mnt = file->f_path.mnt;
> 	struct inode *inode = file->f_inode;
> 
> 	might_sleep();
> 
> 	fsnotify_close(file);
> 	/*
> 	 * The function eventpoll_release() should be the first called
> 
> I came to the conclusion that it gets a file which is NULL and dies when
> trying to get 'mode' below:
> 
> static inline void fsnotify_close(struct file *file)
> {
> 	struct path *path = &file->f_path;
> 	struct inode *inode = file_inode(file);
> 	fmode_t mode = file->f_mode;
> 	__u32 mask = (mode & FMODE_WRITE) ? FS_CLOSE_WRITE : FS_CLOSE_NOWRITE;
> 
> 
> Anyway, I may be wrong on the analysis and can provide the image if
> you want to take a look. I then took a look at which commit may have
> caused the bug and considered 4f5e65a1cc90 (fput: turn "list_head
> delayed_fput_list" into llist_head) and then c7314d74fcb0 ("nfsd
> regression since delayed fput()") but they are quite old and I guess
> someone else would have hit it already if one was the cause. Bottom
> line: I hope the backtrace may give you an idea.

The whole image would be an overkill, but System.map and disassembly of
__fput would be useful...  The thing is, delayed_fput() does this:
        for (; node; node = next) {
                next = llist_next(node);
                __fput(llist_entry(node, struct file, f_u.fu_llist));
        }
and llist_entry() here is just a cast - f_u.fu_list is at offset zero.
So to get NULL passed to __fput() here you'd need node == NULL.  Even
unmapped address that has escaped the loop condition would've oopsed
before reaching __fput() - we *do* fetch node->next (i.e.
file->f_u.fu_list.next) before going into __fput(); that isn't going
to be reordered away.

Besides, f_mode is quite a bit into struct file and dereferencing has
happened at address 0, unless I'm misreading that oops...