Bug 2697 - CIFS driver oopses when multiple machines attempt to lock file
Summary: CIFS driver oopses when multiple machines attempt to lock file
Status: RESOLVED FIXED
Alias: None
Product: CifsVFS
Classification: Unclassified
Component: kernel fs (show other bugs)
Version: 2.6
Hardware: All Linux
: P3 critical
Target Milestone: ---
Assignee: Steve French
QA Contact:
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2005-05-10 15:09 UTC by Ilya A. Volynets
Modified: 2005-05-16 13:55 UTC (History)
0 users

See Also:

Attachments
This is sample program, (1.83 KB, text/plain)
2005-05-10 15:11 UTC, Ilya A. Volynets 		no flags Details
View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Ilya A. Volynets 2005-05-10 15:09:34 UTC 
I have a program that does following:
1. open dir
2. read next entry
3. open the file
4. lock it (tried both flock and fcntl)
5. rename the file
6. unlock
7. close
8. go to #2.

When this program is run on a same cifs-mounted directory from two different
machines, following oops occurs:

Unable to handle kernel NULL pointer dereference at virtual address 00000024
.......<snip>

Call Trace:
 [<f8bd9022>] cifs_buf_release+0x1c/0x40 [cifs]
 [<f8bc8901>] CIFSSMBUnixQPathInfo+0x1e0/0x29e [cifs]
 [<f8bd7665>] cifs_rename+0x277/0x331 [cifs]
 [<c0153898>] vfs_rename_other+0xa3/0xd8
 [<c0153a55>] vfs_rename+0x188/0x403
 [<c0153ec1>] sys_rename+0x1f1/0x220
 [<c02d6f1a>] schedule+0x276/0x420
 [<c0103d4f>] syscall_call+0x7/0xb


I tried it with kernels 2.6.10, 2.6.11, and 2.6.12-rc4
on few different machines. In all cases I was mounting samba share
running on samba-3.0.10
Comment 1 Ilya A. Volynets 2005-05-10 15:11:45 UTC 
Created attachment 1216 [details]
This is sample program,

Attached program produces crash in question fairly reliably for me, when run on
two machines.
Comment 2 Steve French 2005-05-10 20:27:53 UTC 
I just tried this from two clients (roughly cifs version 1.34) to samba 3.0.14
and did not see the oops.

My guess is that it has something to do with the response buffer getting freed
twice but it is odd that it would affect QPathInfo.

Is your kernel compiled with the memory allocation debug configuration options
(which might help a bit)?

In addition - could you reproduce the problem with /proc/fs/cifs/cifsFYI enabled
(set to 1) - that way we can see what happens just before the oops.

I will probably have to add a bit more debug code to this to see what is going
on - presumably the mempool is corrupt.
Comment 3 Ilya A. Volynets 2005-05-11 13:49:55 UTC 
So I tried it again, with driver from 2.6.12-rc4 (v1.34?)

Crash is still reproducable. Here is crash dump with some extra info attached:

 fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 185740 with uid: 0
 fs/cifs/file.c:  inode = 0xcddc9bfc file flags are 0x0 for \ttt\1111
 fs/cifs/transport.c: For smb_command 162
 fs/cifs/transport.c: Sending smb of length 104
 fs/cifs/connect.c: rfc1002 length(big endian)0x6b)
 fs/cifs/file.c: inode unchanged on server
 fs/cifs/inode.c:  Getting info on \ttt\1111
 fs/cifs/cifssmb.c: In QPathInfo (Unix) the path \ttt\1111
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 92
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
 fs/cifs/connect.c: invalid transact2 word count
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Send error in QPathInfo = -2
 fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 185740) rc = -2
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185741 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt\1111111111111111 inode 0xcddc9ab4 count 1
dentry: 0xcdd7720c d_time 164999150 jiffies 164999162
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185741) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 185742 with uid: 0
 fs/cifs/file.c:  inode = 0xcddc9ab4 file flags are 0x0 for \ttt\1111111111111111
 fs/cifs/transport.c: For smb_command 162
 fs/cifs/transport.c: Sending smb of length 128
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Error in Open = -2
 fs/cifs/file.c: cifs_open returned 0xfffffffe
 fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 185742) rc = -2
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185743 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt\111111111 inode 0xcddc996c count 1 dentry:
0xcdb4797c d_time 164999150 jiffies 164999171
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185743) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 185744 with uid: 0
 fs/cifs/file.c:  inode = 0xcddc996c file flags are 0x0 for \ttt\111111111
 fs/cifs/transport.c: For smb_command 162
 fs/cifs/transport.c: Sending smb of length 114
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Error in Open = -2
 fs/cifs/file.c: cifs_open returned 0xfffffffe
 fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 185744) rc = -2
 fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 185745 with uid: 0
 fs/cifs/readdir.c: index not in buffer - could not findnext into it
 fs/cifs/readdir.c: could not find entry
 fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 185745) rc = 0
 fs/cifs/file.c: Closedir inode = 0xcdccd42c with
 fs/cifs/file.c: CIFS VFS: in cifs_closedir as Xid: 185746 with uid: 0
 fs/cifs/file.c: Freeing private data in close dir
 fs/cifs/file.c: freeing smb buf in srch struct in closedir
 fs/cifs/file.c: CIFS VFS: leaving cifs_closedir (xid = 185746) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185747 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt inode 0xcdccd42c count 1 dentry: 0xcd6a5f34
d_time 164528620 jiffies 164999185
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185747) rc = 0
 fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 185748 with uid: 0
 fs/cifs/readdir.c: Full path: \ttt start at: 0
 fs/cifs/cifssmb.c: In FindFirst for \ttt
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 92
 fs/cifs/connect.c: rfc1002 length(big endian)0x2b8)
 fs/cifs/readdir.c: initiate cifs search rc 0
 fs/cifs/readdir.c: found entry - pos_in_buf 0
 fs/cifs/readdir.c: entry 0 found
 fs/cifs/readdir.c: loop through 5 times filling dir for net buf cde20340
 fs/cifs/readdir.c: For .
 fs/cifs/readdir.c: Directory inode
 fs/cifs/readdir.c: new entry cde203f8 old entry cde20388
 fs/cifs/readdir.c: For ..
 fs/cifs/readdir.c: Directory inode
 fs/cifs/readdir.c: new entry cde2046c old entry cde203f8
 fs/cifs/readdir.c: For 11111
 fs/cifs/readdir.c: File inode
 fs/cifs/readdir.c: new entry cde204e4 old entry cde2046c
 fs/cifs/readdir.c: For 11111111111111111
 fs/cifs/readdir.c: File inode
 fs/cifs/readdir.c: new entry cde20574 old entry cde204e4
 fs/cifs/readdir.c: For 1111111111
 fs/cifs/readdir.c: File inode
 fs/cifs/readdir.c: last entry in buf at pos 5 1111111111
 fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 185748) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185749 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt\11111 inode 0xcddc9824 count 1 dentry:
0xcdd770fc d_time 164999187 jiffies 164999188
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185749) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 185750 with uid: 0
 fs/cifs/file.c:  inode = 0xcddc9824 file flags are 0x0 for \ttt\11111
 fs/cifs/transport.c: For smb_command 162
 fs/cifs/transport.c: Sending smb of length 106
 fs/cifs/connect.c: rfc1002 length(big endian)0x6b)
 fs/cifs/file.c: inode unchanged on server
 fs/cifs/inode.c:  Getting info on \ttt\11111
 fs/cifs/cifssmb.c: In QPathInfo (Unix) the path \ttt\11111
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 94
 fs/cifs/connect.c: rfc1002 length(big endian)0xa5)
 fs/cifs/inode.c:  Old time 164999187
 fs/cifs/inode.c:  New time 164999191
 fs/cifs/inode.c: Size 0 and blocks 0
 fs/cifs/inode.c:  File inode
 fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 185750) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185751 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt\11111 inode 0xcddc9824 count 1 dentry:
0xcdd770fc d_time 164999187 jiffies 164999191
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185751) rc = 0
 fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 185752 with uid: 0
 fs/cifs/dir.c:  parent inode = 0xcdccd42c name is: 111111 and dentry = 0xcdd77b9c
 fs/cifs/dir.c:  NULL inode in lookup
 fs/cifs/dir.c:  Full path: \ttt\111111 inode = 0x00000000
 fs/cifs/inode.c:  Getting info on \ttt\111111
 fs/cifs/cifssmb.c: In QPathInfo (Unix) the path \ttt\111111
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 96
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
 fs/cifs/connect.c: invalid transact2 word count
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Send error in QPathInfo = -2
 fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 185752) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_rename as Xid: 185753 with uid: 0
 fs/cifs/cifssmb.c: In CIFSSMBRename
 fs/cifs/transport.c: For smb_command 7
 fs/cifs/transport.c: Sending smb of length 86
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Send error in rename = -2
 fs/cifs/inode.c: rename rc -2
 fs/cifs/inode.c: CIFS VFS: leaving cifs_rename (xid = 185753) rc = -2
 fs/cifs/file.c: Flush inode cddc9824 file cdcc9560 rc 0
 fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 185754 with uid: 0
 fs/cifs/cifssmb.c: In CIFSSMBClose
 fs/cifs/transport.c: For smb_command 4
 fs/cifs/transport.c: Sending smb of length 41
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
 fs/cifs/file.c: closing last open instance for inode cddc9824
 fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 185754) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185755 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt\11111111111111111 inode 0xcddc96dc count 1
dentry: 0xcdd77294 d_time 164999187 jiffies 164999196
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185755) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 185756 with uid: 0
 fs/cifs/file.c:  inode = 0xcddc96dc file flags are 0x0 for \ttt\11111111111111111
 fs/cifs/transport.c: For smb_command 162
 fs/cifs/transport.c: Sending smb of length 130
 fs/cifs/connect.c: rfc1002 length(big endian)0x6b)
 fs/cifs/file.c: inode unchanged on server
 fs/cifs/inode.c:  Getting info on \ttt\11111111111111111
 fs/cifs/cifssmb.c: In QPathInfo (Unix) the path \ttt\11111111111111111
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 118
 fs/cifs/connect.c: rfc1002 length(big endian)0xa5)
 fs/cifs/inode.c:  Old time 164999187
 fs/cifs/inode.c:  New time 164999203
 fs/cifs/inode.c: Size 0 and blocks 0
 fs/cifs/inode.c:  File inode
 fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 185756) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 185757 with uid: 0
 fs/cifs/inode.c: Revalidate: \ttt\11111111111111111 inode 0xcddc96dc count 1
dentry: 0xcdd77294 d_time 164999187 jiffies 164999203
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 185757) rc = 0
 fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 185758 with uid: 0
 fs/cifs/dir.c:  parent inode = 0xcdccd42c name is: 111111111111111111 and
dentry = 0xcdd7797c
 fs/cifs/dir.c:  NULL inode in lookup
 fs/cifs/dir.c:  Full path: \ttt\111111111111111111 inode = 0x00000000
 fs/cifs/inode.c:  Getting info on \ttt\111111111111111111
 fs/cifs/cifssmb.c: In QPathInfo (Unix) the path \ttt\111111111111111111
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 120
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
 fs/cifs/connect.c: invalid transact2 word count
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Send error in QPathInfo = -2
 fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 185758) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_rename as Xid: 185759 with uid: 0
 fs/cifs/cifssmb.c: In CIFSSMBRename
 fs/cifs/transport.c: For smb_command 7
 fs/cifs/transport.c: Sending smb of length 134
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
Status code returned 0xc0000035 NT_STATUS_OBJECT_NAME_COLLISION
 fs/cifs/netmisc.c:  !!Mapping smb error code 183 to POSIX err -17 !!
 fs/cifs/cifssmb.c: Send error in rename = -17
 fs/cifs/cifssmb.c: In QPathInfo (Unix) the path \ttt\11111111111111111
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 118
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
 fs/cifs/connect.c: invalid transact2 word count
Status code returned 0xc0000034 NT_STATUS_OBJECT_NAME_NOT_FOUND
 fs/cifs/netmisc.c:  !!Mapping smb error code 2 to POSIX err -2 !!
 fs/cifs/cifssmb.c: Send error in QPathInfo = -2
 fs/cifs/inode.c:  cifs_unlink, inode = 0xcdccd42c with
 fs/cifs/inode.c: CIFS VFS: in cifs_unlink as Xid: 185760 with uid: 0
 fs/cifs/transport.c: For smb_command 6
 fs/cifs/transport.c: Sending smb of length 86
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
Unable to handle kernel NULL pointer dereference at virtual address 0000002c
 printing eip:
d098bd56
*pde = 00000000
Oops: 0002 [#1]
Modules linked in: cifs nfs lockd sunrpc dm_mirror dm_mod reiserfs eepro100 mii
CPU:    0
EIP:    0060:[<d098bd56>]    Not tainted VLI
EFLAGS: 00010246   (2.6.11.8-vsa-2040)
EIP is at cifs_unlink+0x1b6/0x420 [cifs]
eax: 00000000   ebx: c13635a0   ecx: ce6551a0   edx: cdd7797c
esi: 0002d5a0   edi: 00000000   ebp: cdde0e6c   esp: cdde0e34
ds: 007b   es: 007b   ss: 0068
Process cifscrash (pid: 13237, threadinfo=cdde0000 task=cdc84a00)
Stack: cdde0e5c ce655680 cdadf9a0 0002d59f 00000023 cdd28360 cdd28360 cdadf9a0
       c13635a0 ffffffef cdde0eb0 cdadf9a0 c13635a0 ffffffef cdde0eb0 d098c6b3
       cdccd42c cdd7797c c01041c6 cdde0000 cdac3380 cdac33e4 0002d59f c13635a0
Call Trace:
 [<c0102e35>] show_stack+0x75/0x90
 [<c0102f89>] show_registers+0x119/0x180
 [<c0103155>] die+0xb5/0x130
 [<c010b298>] do_page_fault+0x2f8/0x63a
 [<c0102a5f>] error_code+0x4f/0x60
 [<d098c6b3>] cifs_rename+0x253/0x310 [cifs]
 [<c0152776>] vfs_rename_other+0x76/0xb0
 [<c015292a>] vfs_rename+0x17a/0x360
 [<c0152cbe>] sys_rename+0x1ae/0x1f0
 [<c0102789>] syscall_call+0x7/0xb
Code: 8b 53 0c 52 8b 45 cc 50 8b 45 d0 50 56 e8 43 0a ff ff 83 c4 14 85 c0 89 c7
75 18 8d 76 00 8d bc 27 00 00 00 00 8b 55 0c 8b 42 08 <ff> 48 2c e9 e2 fe ff ff
83 f8 e6 0f 85 d9 fe ff ff c7 45 d8 00
 <7> fs/cifs/file.c: Closedir inode = 0xcdccd42c with
 fs/cifs/file.c: CIFS VFS: in cifs_closedir as Xid: 185761 with uid: 0
 fs/cifs/file.c: Freeing private data in close dir
 fs/cifs/file.c: freeing smb buf in srch struct in closedir
 fs/cifs/file.c: CIFS VFS: leaving cifs_closedir (xid = 185761) rc = 0
 fs/cifs/file.c: Flush inode cddc96dc file cdcc9560 rc 0
 fs/cifs/file.c: CIFS VFS: in cifs_lock as Xid: 185762 with uid: 0
 fs/cifs/file.c: Lock parm: 0x6 flockflags: 0x1 flocktype: 0x2 start: 0 end:
9223372036854775807
 fs/cifs/file.c: Posix
 fs/cifs/file.c: F_UNLCK
 fs/cifs/cifssmb.c: In CIFSSMBLock - timeout 0 numLock 0
 fs/cifs/transport.c: For smb_command 36
 fs/cifs/transport.c: Sending smb of length 71
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
Status code returned 0xc000007e NT_STATUS_RANGE_NOT_LOCKED
 fs/cifs/netmisc.c:  !!Mapping smb error code 158 to POSIX err -37 !!
 fs/cifs/cifssmb.c: Send error in Lock = -37
 fs/cifs/file.c: CIFS VFS: leaving cifs_lock (xid = 185762) rc = -37
 fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 185763 with uid: 0
 fs/cifs/cifssmb.c: In CIFSSMBClose
 fs/cifs/transport.c: For smb_command 4
 fs/cifs/transport.c: Sending smb of length 41
 fs/cifs/connect.c: rfc1002 length(big endian)0x27)
 fs/cifs/file.c: closing last open instance for inode cddc96dc
 fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 185763) rc = 0