[Samba] oplocks issue when trying to copy file

Philip Ong phong at nvidia.com
Thu Sep 29 02:21:56 MDT 2011


Kernel tried on Centos 4.5 was 2.6.38.8

-----Original Message-----
From: Philip Ong 
Sent: Wednesday, September 28, 2011 3:44 PM
To: Philip Ong; 'samba at lists.samba.org'
Subject: RE: oplocks issue when trying to copy file 

I also tried this on Centos 4.5 and it has the same results so it is probably not distro related.

-----Original Message-----
From: Philip Ong 
Sent: Tuesday, September 27, 2011 10:41 PM
To: samba at lists.samba.org
Cc: Philip Ong
Subject: oplocks issue when trying to copy file 

I'm not sure if this a Kernel/samba or NFS issue. We run this on Centos 5.6 using a kernel.org kernel.

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,
Phil
-----------------------------------------------------------------------------------
This email message is for the sole use of the intended recipient(s) and may contain
confidential information.  Any unauthorized review, use, disclosure or distribution
is prohibited.  If you are not the intended recipient, please contact the sender by
reply email and destroy all copies of the original message.
-----------------------------------------------------------------------------------


More information about the samba mailing list