Bug 453462

I've got a preliminary patchset to fix this in the kernels on my people page. It
consists of ~145 patches from upstream backported for RHEL5.3. Testing uncovered
a couple of upstream bugs that I've pushed out patches for.

With those fixed, testing looks good so far, but there are still some to-do's:

1) verify kerberos support. It's built into these kernels, but not yet tested.

2) verify whether we need any keyctl patches for kerberos (we may need the one
that has it do a vmalloc for large blobs).

3) fix DFS support. Not strictly required, but I think we may eventually want to
support it (and we'll be getting the necessary userspace program "for free" with
the kerberos support). The main problem I see now is a difference in workqueues.
This is probably fixable, but for now DFS is disabled.

 

Ran fsstress on the CIFS mount overnight and it survived until this morning.
I'll plan to re-run it with unix extensions disabled so that we make sure to
exercise those codepaths as well. I did get some messages in the ring buffer:

 CIFS VFS: No writable handles for inode
 CIFS VFS: No writable handles for inode
 CIFS VFS: writes pending, delay free of handle
 CIFS VFS: Write2 ret -9, wrote 0

...my guess is that these are upstream issues. I'll plan to look them over and
see if they're something to be concerned about and maybe also run a rawhide
kernel with the same test to see if these messages pop up there as well.

This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux maintenance release.  Product Management has requested
further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed
products.  This request is not yet committed for inclusion in an Update
release.

Ran fsstress on this kernel over the holiday weekend. It survived and the only
messages in the ring buffer were some of these:

  CIFS VFS: No writable handles for inode

...it looks like this comes from cifs_writepages, and pops up when we look for a
writeable filehandle for an inode but there isn't one. So we may have a race of
some sort (likely an upstream bug) where writeable filehandles are being allowed
to close before all of the dirty pages are flushed, or pages are allowed to
become dirty after the flush occurs.

Either way I need to confirm whether this happens on rawhide and also see
whether it happens on earlier RHEL5 kernels.

The fsstress run was using this command line:

/usr/lib/ltp/testcases/network/nfs/nfs_fsstress/fsstress -d /mnt/cifs/CIFS1 -l 0
-n 1000 -p 8 -r

...I may consider adding this to RHTS for both CIFS and NFS (possibly with a
bigger number of threads and operations).

Yep. Running the same test on a recent rawhide kernel shows:

SELinux: initialized (dev cifs, type cifs), uses genfs_contexts
 CIFS VFS: No writable handles for inode

...so this is an upstream problem. I'll need to look over the code more closely
and see if I can determine the cause.

Hit a lockdep trace this morning when testing with krb5:

=======================================================
[ INFO: possible circular locking dependency detected ]
2.6.18-96.el5.jtltest.37debug #1
-------------------------------------------------------
cifs.spnego/2378 is trying to acquire lock:
 (&key->sem){----}, at: [<ffffffff801258d9>] key_revoke+0x15/0x3b

but task is already holding lock:
 (key_construction_sem){--..}, at: [<ffffffff80125a18>]
__key_instantiate_and_link+0x2f/0xd1

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (key_construction_sem){--..}:
       [<ffffffff800a809f>] __lock_acquire+0x9a9/0xadf
       [<ffffffff800a8995>] lock_acquire+0x55/0x70
       [<ffffffff80125a18>] __key_instantiate_and_link+0x2f/0xd1
       [<ffffffff800a4d59>] down_write+0x3c/0x68
       [<ffffffff80125a18>] __key_instantiate_and_link+0x2f/0xd1
       [<ffffffff80125afb>] key_instantiate_and_link+0x41/0x6d
       [<ffffffff80125b0f>] key_instantiate_and_link+0x55/0x6d
       [<ffffffff80126fc8>] keyring_alloc+0x46/0x5e
       [<ffffffff80128763>] alloc_uid_keyring+0x78/0xa6
       [<ffffffff8000ada6>] kmem_cache_alloc+0xdf/0xeb
       [<ffffffff8009a87c>] alloc_uid+0xa9/0x16f
       [<ffffffff8009d2f0>] set_user+0xf/0x98
       [<ffffffff8009ea6a>] sys_setuid+0x7d/0x154
       [<ffffffff80060116>] system_call+0x7e/0x83
       [<ffffffffffffffff>] 0xffffffffffffffff

-> #0 (&key->sem){----}:
       [<ffffffff800a7fb5>] __lock_acquire+0x8bf/0xadf
       [<ffffffff800a8995>] lock_acquire+0x55/0x70
       [<ffffffff801258d9>] key_revoke+0x15/0x3b
       [<ffffffff800a4d59>] down_write+0x3c/0x68
       [<ffffffff801258d9>] key_revoke+0x15/0x3b
       [<ffffffff80125a78>] __key_instantiate_and_link+0x8f/0xd1
       [<ffffffff80127503>] keyctl_instantiate_key+0xe0/0x137
       [<ffffffff800602a6>] tracesys+0xd5/0xdf
       [<ffffffffffffffff>] 0xffffffffffffffff

other info that might help us debug this:

1 lock held by cifs.spnego/2378:
 #0:  (key_construction_sem){--..}, at: [<ffffffff80125a18>]
__key_instantiate_and_link+0x2f/0xd1

stack backtrace:

Call Trace:
 [<ffffffff800a699e>] print_circular_bug_tail+0x65/0x6e
 [<ffffffff800a7fb5>] __lock_acquire+0x8bf/0xadf
 [<ffffffff800a8995>] lock_acquire+0x55/0x70
 [<ffffffff801258d9>] key_revoke+0x15/0x3b
 [<ffffffff800a4d59>] down_write+0x3c/0x68
 [<ffffffff801258d9>] key_revoke+0x15/0x3b
 [<ffffffff80125a78>] __key_instantiate_and_link+0x8f/0xd1
 [<ffffffff80127503>] keyctl_instantiate_key+0xe0/0x137
 [<ffffffff800602a6>] tracesys+0xd5/0xdf


I think we'll need the patch from this:

http://lkml.org/lkml/2007/9/17/209

Spun off last lockdep warning to bug 456320 and I think I have a fix for it.
This morning, I got a new one (unrelated to keys API):

=======================================================
[ INFO: possible circular locking dependency detected ]
2.6.18-98.el5.jtltest.38.bz456320.1debug #1
-------------------------------------------------------
test5/2483 is trying to acquire lock:
 (sk_lock-AF_INET){--..}, at: [<ffffffff800270d2>] tcp_sendmsg+0x1c/0xb2f

but task is already holding lock:
 (&inode->i_alloc_sem){--..}, at: [<ffffffff8002e454>] notify_change+0xf5/0x2e0

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&inode->i_alloc_sem){--..}:
       [<ffffffff800a817c>] __lock_acquire+0x9a9/0xadf
       [<ffffffff800a8a72>] lock_acquire+0x55/0x70
       [<ffffffff8002e454>] notify_change+0xf5/0x2e0
       [<ffffffff800a4e36>] down_write+0x3c/0x68
       [<ffffffff8002e454>] notify_change+0xf5/0x2e0
       [<ffffffff800e358d>] do_truncate+0x50/0x6b
       [<ffffffff8005197c>] get_write_access+0x40/0x46
       [<ffffffff80012cf1>] may_open+0x1d3/0x22e
       [<ffffffff8001bc81>] open_namei+0x2c6/0x6dd
       [<ffffffff800289c6>] do_filp_open+0x1c/0x38
       [<ffffffff800683ef>] _spin_unlock+0x17/0x20
       [<ffffffff800167a7>] get_unused_fd+0xf9/0x107
       [<ffffffff8001a704>] do_sys_open+0x44/0xbe
       [<ffffffff80060116>] system_call+0x7e/0x83
       [<ffffffffffffffff>] 0xffffffffffffffff

-> #2 (&sysfs_inode_imutex_key){--..}:
       [<ffffffff800a817c>] __lock_acquire+0x9a9/0xadf
       [<ffffffff8010f6df>] create_dir+0x26/0x1d7
       [<ffffffff800a8a72>] lock_acquire+0x55/0x70
       [<ffffffff8010f6df>] create_dir+0x26/0x1d7
       [<ffffffff800671c0>] mutex_lock_nested+0x104/0x29c
       [<ffffffff800a819d>] __lock_acquire+0x9ca/0xadf
       [<ffffffff8010f6df>] create_dir+0x26/0x1d7
       [<ffffffff8010fc67>] sysfs_create_dir+0x58/0x76
       [<ffffffff8015144c>] kobject_add+0xdb/0x198
       [<ffffffff801be765>] class_device_add+0xb2/0x465
       [<ffffffff8005a6ff>] kobject_get+0x12/0x17
       [<ffffffff80225265>] register_netdevice+0x270/0x33e
       [<ffffffff8022538c>] register_netdev+0x59/0x67
       [<ffffffff80464d40>] net_olddevs_init+0xb/0xac
       [<ffffffff80448a79>] init+0x1f9/0x2fc
       [<ffffffff80068885>] _spin_unlock_irq+0x24/0x27
       [<ffffffff80067f86>] trace_hardirqs_on_thunk+0x35/0x37
       [<ffffffff80061079>] child_rip+0xa/0x11
       [<ffffffff80068885>] _spin_unlock_irq+0x24/0x27
       [<ffffffff800606a8>] restore_args+0x0/0x30
       [<ffffffff80179a59>] acpi_ds_init_one_object+0x0/0x80
       [<ffffffff80448880>] init+0x0/0x2fc
       [<ffffffff8006106f>] child_rip+0x0/0x11
       [<ffffffffffffffff>] 0xffffffffffffffff

-> #1 (rtnl_mutex){--..}:
       [<ffffffff800a817c>] __lock_acquire+0x9a9/0xadf
       [<ffffffff8025acf8>] ip_mc_leave_group+0x23/0xb7
       [<ffffffff800a8a72>] lock_acquire+0x55/0x70
       [<ffffffff8025acf8>] ip_mc_leave_group+0x23/0xb7
       [<ffffffff800671c0>] mutex_lock_nested+0x104/0x29c
       [<ffffffff8025acf8>] ip_mc_leave_group+0x23/0xb7
       [<ffffffff802451b0>] do_ip_setsockopt+0x6d1/0x9bf
       [<ffffffff800a575e>] lock_release_holdtime+0x27/0x48
       [<ffffffff800a575e>] lock_release_holdtime+0x27/0x48
       [<ffffffff8006a85e>] do_page_fault+0x503/0x835
       [<ffffffff8012cbf6>] socket_has_perm+0x5b/0x68
       [<ffffffff80245556>] ip_setsockopt+0x22/0x78
       [<ffffffff8021c973>] sys_setsockopt+0x91/0xb7
       [<ffffffff800602a6>] tracesys+0xd5/0xdf
       [<ffffffffffffffff>] 0xffffffffffffffff

-> #0 (sk_lock-AF_INET){--..}:
       [<ffffffff800a5037>] print_stack_trace+0x59/0x68
       [<ffffffff800a8092>] __lock_acquire+0x8bf/0xadf
       [<ffffffff800a8a72>] lock_acquire+0x55/0x70
       [<ffffffff800270d2>] tcp_sendmsg+0x1c/0xb2f
       [<ffffffff80035466>] lock_sock+0xd4/0xe4
       [<ffffffff80096e91>] _local_bh_enable+0xcb/0xe0
       [<ffffffff800606a8>] restore_args+0x0/0x30
       [<ffffffff800270d2>] tcp_sendmsg+0x1c/0xb2f
       [<ffffffff80057540>] sock_sendmsg+0xf3/0x110
       [<ffffffff800a2bb6>] autoremove_wake_function+0x0/0x2e
       [<ffffffff800a10e4>] kernel_text_address+0x1a/0x26
       [<ffffffff8006f4e2>] dump_trace+0x211/0x23a
       [<ffffffff800a6d3d>] find_usage_backwards+0x5f/0x88
       [<ffffffff8840221a>] MD5Final+0xaf/0xc2 [cifs]
       [<ffffffff884032ec>] cifs_calculate_signature+0x55/0x69 [cifs]
       [<ffffffff8021d891>] kernel_sendmsg+0x35/0x47
       [<ffffffff883ff38e>] smb_send+0xa3/0x151 [cifs]
       [<ffffffff883ff5de>] SendReceive+0x1a2/0x448 [cifs]
       [<ffffffff800a812f>] __lock_acquire+0x95c/0xadf
       [<ffffffff883e758a>] CIFSSMBSetEOF+0x20d/0x25b [cifs]
       [<ffffffff883fa430>] cifs_set_file_size+0x110/0x3b7 [cifs]
       [<ffffffff883faa89>] cifs_setattr+0x3b2/0x6f6 [cifs]
       [<ffffffff8002e454>] notify_change+0xf5/0x2e0
       [<ffffffff8002e4a4>] notify_change+0x145/0x2e0
       [<ffffffff800e358d>] do_truncate+0x50/0x6b
       [<ffffffff8005197c>] get_write_access+0x40/0x46
       [<ffffffff80012cf1>] may_open+0x1d3/0x22e
       [<ffffffff8001bc81>] open_namei+0x2c6/0x6dd
       [<ffffffff800289c6>] do_filp_open+0x1c/0x38
       [<ffffffff800683ef>] _spin_unlock+0x17/0x20
       [<ffffffff800167a7>] get_unused_fd+0xf9/0x107
       [<ffffffff8001a704>] do_sys_open+0x44/0xbe
       [<ffffffff800602a6>] tracesys+0xd5/0xdf
       [<ffffffffffffffff>] 0xffffffffffffffff

other info that might help us debug this:

2 locks held by test5/2483:
 #0:  (&inode->i_mutex){--..}, at: [<ffffffff800e3582>] do_truncate+0x45/0x6b
 #1:  (&inode->i_alloc_sem){--..}, at: [<ffffffff8002e454>] notify_change+0xf5/0x2e0

stack backtrace:

Call Trace:
 [<ffffffff800a6a7b>] print_circular_bug_tail+0x65/0x6e
 [<ffffffff800a5037>] print_stack_trace+0x59/0x68
 [<ffffffff800a8092>] __lock_acquire+0x8bf/0xadf
 [<ffffffff800a8a72>] lock_acquire+0x55/0x70
 [<ffffffff800270d2>] tcp_sendmsg+0x1c/0xb2f
 [<ffffffff80035466>] lock_sock+0xd4/0xe4
 [<ffffffff80096e91>] _local_bh_enable+0xcb/0xe0
 [<ffffffff800606a8>] restore_args+0x0/0x30
 [<ffffffff800270d2>] tcp_sendmsg+0x1c/0xb2f
 [<ffffffff80057540>] sock_sendmsg+0xf3/0x110
 [<ffffffff800a2bb6>] autoremove_wake_function+0x0/0x2e
 [<ffffffff800a10e4>] kernel_text_address+0x1a/0x26
 [<ffffffff8006f4e2>] dump_trace+0x211/0x23a
 [<ffffffff800a6d3d>] find_usage_backwards+0x5f/0x88
 [<ffffffff8840221a>] :cifs:MD5Final+0xaf/0xc2
 [<ffffffff884032ec>] :cifs:cifs_calculate_signature+0x55/0x69
 [<ffffffff8021d891>] kernel_sendmsg+0x35/0x47
 [<ffffffff883ff38e>] :cifs:smb_send+0xa3/0x151
 [<ffffffff883ff5de>] :cifs:SendReceive+0x1a2/0x448
 [<ffffffff800a812f>] __lock_acquire+0x95c/0xadf
 [<ffffffff883e758a>] :cifs:CIFSSMBSetEOF+0x20d/0x25b
 [<ffffffff883fa430>] :cifs:cifs_set_file_size+0x110/0x3b7
 [<ffffffff883faa89>] :cifs:cifs_setattr+0x3b2/0x6f6
 [<ffffffff8002e454>] notify_change+0xf5/0x2e0
 [<ffffffff8002e4a4>] notify_change+0x145/0x2e0
 [<ffffffff800e358d>] do_truncate+0x50/0x6b
 [<ffffffff8005197c>] get_write_access+0x40/0x46
 [<ffffffff80012cf1>] may_open+0x1d3/0x22e
 [<ffffffff8001bc81>] open_namei+0x2c6/0x6dd
 [<ffffffff800289c6>] do_filp_open+0x1c/0x38
 [<ffffffff800683ef>] _spin_unlock+0x17/0x20
 [<ffffffff800167a7>] get_unused_fd+0xf9/0x107
 [<ffffffff8001a704>] do_sys_open+0x44/0xbe
 [<ffffffff800602a6>] tracesys+0xd5/0xdf

I think the last lockdep warning means that we need to do something like this
patch, but for CIFS:

http://programming.kicks-ass.net/kernel-patches/lockdep/nfs-socket-lockdep.patch

I've also seen some postings from LKML where people have hit the same warning
with CIFS, so this looks like another upstream problem.

*** Bug 456423 has been marked as a duplicate of this bug. ***

*** Bug 446249 has been marked as a duplicate of this bug. ***

*** Bug 456320 has been marked as a duplicate of this bug. ***

in kernel-2.6.18-113.el5
You can download this test kernel from http://people.redhat.com/dzickus/el5

The most recent patchset has DFS enabled. DFS is the Microsoft distributed filesystem. It essentially allows the server to present entries that act as referrals to other servers or shares. Sort of like a symlink that points to a different share or server...

This bug (feature request) has been marked for inclusion in the Red Hat
Enterprise Linux 5.3 Release Notes.

To aid in the development of relevant and accurate release notes, please fill
out the "Release Notes" field above with the following 4 pieces of information:


Cause:   What actions or circumstances induced the feature request.

Consequence:  What action was inhibited by the feature's absence.

Fix:   What was done to implement the feature.

Result:  now happens when the actions or circumstances above occur. (NB: this
is not the same as 'the feature request was fulfilled'

Release note added. If any revisions are required, please set the 
"requires_release_notes" flag to "?" and edit the "Release Notes" field accordingly.
All revisions will be proofread by the Engineering Content Services team.

New Contents:
Cause: Desire to mount using krb5 authentication

Consequence:  The ability to mount using krb5 authentication

Fix: Added the ability for the user to request krb5 authentication and the kernel to ask a userspace program for proper krb5 tickets to authenticate

Result: When someone tries to mount with sec=krb5 (or sec=krb5i), the kernel will attempt to call out to the cifs.upcall userspace program. That program will return a SPNEGO security blob to the kernel. The kernel can then use this blob to authenticate with the server and perform the mount.

-----------------------[snip]-------------------

Cause: Desire to allow the CIFS client to chase DFS referrals

Consequence: When the client found a DFS referral, it would just return -EREMOTE and not follow it.

Fix: Added the ability to transparently follow the DFS referral and mount it, including the ability to ask userspace for DNS resolution

Result: When someone tries to access a DFS link, the client will now query the link for the UNC to which it points. If the referral UNC has a hostname in it, the kernel will then call out to cifs.upcall and ask it to resolve the name. It will then mount the share at the proper point. This allows users to transparently walk into DFS referrals from a mounted share.

Release note updated. If any revisions are required, please set the 
"requires_release_notes"  flag to "?" and edit the "Release Notes" field accordingly.
All revisions will be proofread by the Engineering Content Services team.

Diffed Contents:
@@ -1,17 +1 @@
-Cause: Desire to mount using krb5 authentication
+The mount command now supports Kerberos authentication when mounting filesystems via Samba. The "sec=krb5" or "sec=krb5i" switch allows the kernel to call a userspace application (cifs.upcall) which returns a SPNEGO (Simple and Protected GSSAPI Negotiation Mechanism) security blob (Binary Large OBject). The kernel can then use this blob to authenticate with the server and mount the requested filesystem.-
-Consequence:  The ability to mount using krb5 authentication
-
-Fix: Added the ability for the user to request krb5 authentication and the kernel to ask a userspace program for proper krb5 tickets to authenticate
-
-Result: When someone tries to mount with sec=krb5 (or sec=krb5i), the kernel will attempt to call out to the cifs.upcall userspace program. That program will return a SPNEGO security blob to the kernel. The kernel can then use this blob to authenticate with the server and perform the mount.
-
------------------------[snip]-------------------
-
-Cause: Desire to allow the CIFS client to chase DFS referrals
-
-Consequence: When the client found a DFS referral, it would just return -EREMOTE and not follow it.
-
-Fix: Added the ability to transparently follow the DFS referral and mount it, including the ability to ask userspace for DNS resolution
-
-Result: When someone tries to access a DFS link, the client will now query the link for the UNC to which it points. If the referral UNC has a hostname in it, the kernel will then call out to cifs.upcall and ask it to resolve the name. It will then mount the share at the proper point. This allows users to transparently walk into DFS referrals from a mounted share.

An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2009-0225.html