Bug 8499 - oplocks issue when trying to copy file
oplocks issue when trying to copy file
Status: NEW
Product: Samba 3.6
Classification: Unclassified
Component: Build environment
3.6.0
x64 Linux
: P5 normal
: ---
Assigned To: Volker Lendecke
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2011-09-29 12:18 UTC by pongjr
Modified: 2012-09-12 22:28 UTC (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description pongjr 2011-09-29 12:18:16 UTC
I'm not sure if this a Kernel/samba or NFS issue. We run this on Centos 5.6 using a kernel.org kernel. Also tried on Centos 4.5 (2.6.38.8).

Please find below the problem description

When trying to copy a file to a samba share which has NFS backend on 2.6.36.3 or newer Linux kernel following message is displayed on windows client 

“An unexpected error is keeping you from copying the file. If you continue to receive this error, you can use the error code to search for help with this problem.
Error 0x80070021: The process cannot access the file because another process has locked a portion of the file”

I am able to delete a file within the same directory structure. I am also able to create a file or folder by right-clicking within Windows Explorer on XP. Below are the logs generated by samba in debug mode. The main line of interest was:

  linux_set_kernel_oplock: Refused oplock on file home/foo/open/test.cfg, fd = 33, file_id = 17:aa41ab:0. (Invalid argument)


Please note “test.cfg" was the file which we were trying to copy from windows

  check_reduced_name [home/foo/open/test.cfg] [/]
[2011/09/27 17:41:41.128330, 10] smbd/vfs.c:968(check_reduced_name)
  check_reduced_name realpath [home/foo/open/test.cfg] -> [/home/foo/open/test.cfg]
[2011/09/27 17:41:41.128339,  3] smbd/vfs.c:1038(check_reduced_name)
  check_reduced_name: home/foo/open/test.cfg reduced to /home/foo/open/test.cfg
[2011/09/27 17:41:41.128348, 10] smbd/open.c:3414(create_file_default)
  create_file: access_mask = 0x6019f file_attributes = 0x20, share_access = 0x0, create_disposition = 0x2 create_options = 0x44 oplock_request = 0x3 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = home/foo/open/test.cfg
[2011/09/27 17:41:41.128359,  3] smbd/vfs.c:881(check_reduced_name)
  check_reduced_name [home/foo/open/test.cfg] [/]
[2011/09/27 17:41:41.128377, 10] smbd/vfs.c:968(check_reduced_name)
  check_reduced_name realpath [home/foo/open/test.cfg] -> [/home/foo/open/test.cfg]
[2011/09/27 17:41:41.128386,  3] smbd/vfs.c:1038(check_reduced_name)
  check_reduced_name: home/foo/open/test.cfg reduced to /home/foo/open/test.cfg
[2011/09/27 17:41:41.128394, 10] smbd/open.c:2941(create_file_unixpath)
  create_file_unixpath: access_mask = 0x6019f file_attributes = 0x20, share_access = 0x0, create_disposition = 0x2 create_options = 0x44 oplock _request = 0x3 ea_list = 0x(nil), sd = 0x(nil), fname = home/foo/open/test.cfg
[2011/09/27 17:41:41.128406,  5] smbd/files.c:119(file_new)
  allocated file structure 14342, fnum = 18438 (4 used)
[2011/09/27 17:41:41.128416,  3] smbd/dosmode.c:166(unix_mode)
  unix_mode(home/foo/open/test.cfg) returning 0744
[2011/09/27 17:41:41.128424, 10] smbd/open.c:1556(open_file_ntcreate)
  open_file_ntcreate: fname=home/foo/open/test.cfg, dos_attrs=0x20 access_mask=0x6019f share_access=0x0 create_disposition = 0x2 create_options
=0x44 unix mode=0744 oplock_request=3
[2011/09/27 17:41:41.128434,  3] smbd/vfs.c:881(check_reduced_name)
  check_reduced_name [home/foo/open/test.cfg] [/]
[2011/09/27 17:41:41.128462, 10] smbd/vfs.c:968(check_reduced_name)
  check_reduced_name realpath [home/foo/open/test.cfg] -> [/home/foo/open/test.cfg]
[2011/09/27 17:41:41.128471,  3] smbd/vfs.c:1038(check_reduced_name)
  check_reduced_name: home/foo/open/test.cfg reduced to /home/foo/open/test.cfg
[2011/09/27 17:41:41.128480, 10] smbd/open.c:1738(open_file_ntcreate)
  open_file_ntcreate: fname=home/foo/open/test.cfg, after mapping access_mask=0x6019f
[2011/09/27 17:41:41.128489,  4] smbd/open.c:2000(open_file_ntcreate)
  calling open_file with flags=0x2 flags2=0xC0 mode=0744, access_mask = 0x6019f, open_access_mask = 0x6019f
[2011/09/27 17:41:41.132844, 10] smbd/open.c:180(fd_open)
  fd_open: name home/foo/open/test.cfg, flags = 0302 mode = 0744, fd = 33.
[2011/09/27 17:41:41.132887, 10] smbd/notify_internal.c:890(notify_trigger)
  notify_trigger called action=0x1, filter=0x1, path=//home/foo/open/test.cfg
[2011/09/27 17:41:41.132897,  2] smbd/open.c:657(open_file)
  jneil opened file home/foo/open/test.cfg read=Yes write=Yes (numopen=4)
[2011/09/27 17:41:41.132909, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
  Locking key 1700000000000000AB41
[2011/09/27 17:41:41.132919, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
  Allocated locked data 0x0x7ffff82393a0
[2011/09/27 17:41:41.132938, 10] smbd/open.c:1057(delay_for_oplocks)
  delay_for_oplocks: oplock type 0x3 on file home/foo/open/test.cfg
[2011/09/27 17:41:41.132947, 10] smbd/open.c:1057(delay_for_oplocks)
  delay_for_oplocks: oplock type 0x3 on file home/foo/open/test.cfg
[2011/09/27 17:41:41.267573,  3] smbd/oplock_linux.c:120(linux_set_kernel_oplock)
  linux_set_kernel_oplock: Refused oplock on file home/foo/open/test.cfg, fd = 33, file_id = 17:aa41ab:0. (Invalid argument)
[2011/09/27 17:41:41.267612, 10] smbd/dosmode.c:701(file_set_dosmode)
  file_set_dosmode: setting dos mode 0x20 on file home/foo/open/test.cfg
[2011/09/27 17:41:41.267631,  8] smbd/dosmode.c:613(dos_mode)
  dos_mode: home/foo/open/test.cfg
[2011/09/27 17:41:41.267640,  8] smbd/dosmode.c:207(dos_mode_from_sbuf)
  dos_mode_from_sbuf returning a
[2011/09/27 17:41:41.267648,  8] smbd/dosmode.c:666(dos_mode)
  dos_mode returning a
[2011/09/27 17:41:41.267655,  3] smbd/dosmode.c:166(unix_mode)
  unix_mode(home/foo/open/test.cfg) returning 0744
[2011/09/27 17:41:41.270793, 10] locking/locking.c:726(unparse_share_modes)
  unparse_share_modes: del: 0, owrt: Tue 27 Sep 2011 05:41:41 PM PDT PDT cwrt: Wed 31 Dec 1969 04:00:00 PM PST PST, tok: 0, num: 1
[2011/09/27 17:41:41.270841, 10] locking/locking.c:518(print_share_mode_table)
  print_share_mode_table: share_mode_entry[0]:  pid = 6668, share_access = 0x0, private_options = 0x44, access_mask = 0x6019f, mid = 0x0, type= 0x0, gen_id = 229, uid = 1917, flags = 0, file_id 17:aa41ab:0
[2011/09/27 17:41:41.270856, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
  Unlocking key 1700000000000000AB41
[2011/09/27 17:41:41.270869, 10] smbd/open.c:3231(create_file_unixpath)
  create_file_unixpath: info=2
[2011/09/27 17:41:41.270877, 10] smbd/open.c:3487(create_file_default)
  create_file: info=2
[2011/09/27 17:41:41.270886,  8] smbd/dosmode.c:613(dos_mode)
  dos_mode: home/foo/open/test.cfg
[2011/09/27 17:41:41.270894,  8] smbd/dosmode.c:207(dos_mode_from_sbuf)
  dos_mode_from_sbuf returning a
[2011/09/27 17:41:41.270901,  8] smbd/dosmode.c:666(dos_mode)
  dos_mode returning a
[2011/09/27 17:41:41.270912, 10] locking/locking.c:552(parse_share_modes)
  parse_share_modes: delete_on_close: 0, owrt: Tue 27 Sep 2011 05:41:41 PM PDT PDT, cwrt: Wed 31 Dec 1969 04:00:00 PM PST PST, tok: 0, num_shar
e_modes: 1
[2011/09/27 17:41:41.270940, 10] locking/locking.c:655(parse_share_modes)
  parse_share_modes: share_mode_entry[0]:  pid = 6668, share_access = 0x0, private_options = 0x44, access_mask = 0x6019f, mid = 0x0, type= 0x0, gen_id = 229, uid = 1917, flags = 0, file_id 17:aa41ab:0
[2011/09/27 17:41:41.270955, 10] smbd/file_access.c:190(can_access_file_data)
  can_access_file_data: requesting 0x2 on file home/foo/open/test.cfg
[2011/09/27 17:41:41.270965,  5] smbd/nttrans.c:722(reply_ntcreate_and_X)
  reply_ntcreate_and_X: fnum = 18438, open name = home/foo/open/test.cfg
[2011/09/27 17:41:41.332071, 10] lib/util_sock.c:731(read_smb_length_return_keepalive)
  got smb length of 72
[2011/09/27 17:41:41.332100,  6] smbd/process.c:1486(process_smb)
  got message type 0x0 of len 0x48
[2011/09/27 17:41:41.332114,  3] smbd/process.c:1489(process_smb)
  Transaction 879 of length 76 (0 toread)
[2011/09/27 17:41:41.332123,  5] lib/util.c:617(show_msg)
[2011/09/27 17:41:41.332128,  5] lib/util.c:627(show_msg)



We have tried following versions of samba and behavior is same
3.0.33-3.29.el5_7.4
3.5.11
3.6.0

It looks like the issue is with how samba/kernel are handling the oplocks requested by Windows client on NFS file systems 

However we have found two workarounds for it

1)	Disable kernel oplocks in smb.conf by putting kernel oplocks = no
2)	Mount the NFS file system with nolock option

Any help here is much appreciated.

Thanks
Comment 1 pongjr 2011-10-20 08:07:31 UTC
I've narrowed this problem down to a kernel patch that is applied in 2.6.36.3. I replaced file.c from 2.6.36.2 into 2.6.36.3 and Samba works fine. The problem is I'm not sure if Samba needs to be fixed or the kernel needs to be. Anyone know what the right action is? One thing I noticed was the invalid argument being sent in the debugging log.

"  linux_set_kernel_oplock: Refused oplock on file home/foo/open/test.cfg, fd = 33, file_id = 17:aa41ab:0. (Invalid argument)"

Any advice would help.

Thanks,
Phil


The commit 129a84de2347002f09721cda3155ccfd19fade40 (locks: fix F_GETLK
regression (failure to find conflicts)) fixed the posix_test_lock()
function by itself, however, its usage in NFS changed by the commit
9d6a8c5c213e34c475e72b245a8eb709258e968c (locks: give posix_test_lock
same interface as ->lock) remained broken - subsequent NFS-specific
locking code received F_UNLCK instead of the user-specified lock type.
To fix the problem, fl->fl_type needs to be saved before the
posix_test_lock() call and restored if no local conflicts were reported.

Reference: https://bugzilla.kernel.org/show_bug.cgi?id=23892
Tested-by: Alexander Morozov <amorozov@xxxxxxxxxxx>
Signed-off-by: Sergey Vlasov <vsu@xxxxxxxxxxx>
Signed-off-by: Trond Myklebust <Trond.Myklebust@xxxxxxxxxx>
Signed-off-by: Greg Kroah-Hartman <gregkh@xxxxxxx>
Signed-off-by: Andi Kleen <ak@xxxxxxxxxxxxxxx>

---
fs/nfs/file.c | 2 ++
1 file changed, 2 insertions(+)

Index: linux-2.6.35.y/fs/nfs/file.c
===================================================================
--- linux-2.6.35.y.orig/fs/nfs/file.c
+++ linux-2.6.35.y/fs/nfs/file.c
@@ -696,6 +696,7 @@ static int do_getlk(struct file *filp, i
{
struct inode *inode = filp->f_mapping->host;
int status = 0;
+	unsigned int saved_type = fl->fl_type;

/* Try local locking first */
posix_test_lock(filp, fl);
@@ -703,6 +704,7 @@ static int do_getlk(struct file *filp, i
/* found a conflict */
goto out;
}
+	fl->fl_type = saved_type;

if (nfs_have_delegation(inode, FMODE_READ))
goto out_noconflict;
--