On some of our WinXP sp2 PC's we get random "Access Denied" errors when trying to open files from the server. When you get the error, and try again, it usually works, without any changing in permissions or whatever. Samba version: samba-3.0.25b-1.el5_1.4 OS: CentOS 5 with kernel 2.6.18-53.1.6.el5 (SMP) I have a debuglevel 10 logfile of the problem, together with a complete tcpdump network trace of the same traffic. However it's too large to attach here (logfile 8MB, network trace 19 MB). However feel free to contact me, and I can deliver it. My own investigation in this problem noticed the following differences in the log file. When the access succeeds, I find sequences like this in the log: [2008/03/12 13:10:04, 10] smbd/open.c:fd_open(67) fd_open: name Invoicing_xxxx.xls, flags = 00 mode = 0775, fd = 26. [2008/03/12 13:10:04, 2] smbd/open.c:open_file(391) Nathalie opened file Invoicing_xxxx.xls read=Yes write=No (numopen=1) [2008/03/12 13:10:04, 3] smbd/oplock_linux.c:linux_set_kernel_oplock(180) linux_set_kernel_oplock: got kernel oplock on file Invoicing_xxxx.xls, dev = fd02, inode = 103023223, file_id = 7 [2008/03/12 13:10:04, 5] smbd/oplock.c:set_file_oplock(126) set_file_oplock: granted oplock on file Invoicing_xxxx.xls, 0xfd02/103023223/7, tv_sec = 47d7c81c, tv_usec = 20b96 [2008/03/12 13:10:04, 10] locking/locking.c:unparse_share_modes(665) unparse_share_modes: del: 0, tok = 0, num: 1 [2008/03/12 13:10:04, 10] locking/locking.c:print_share_mode_table(482) print_share_mode_table: share_mode_entry[0]: pid = 13174, share_access = 0x7, private_options = 0x840, access_mask = 0x20189, mid = 0x0, type= 0x3, file_id = 7, uid = 1030, flags = 0, dev = 0xfd02, inode = 103023223 [2008/03/12 13:10:05, 10] smbd/open.c:fd_open(67) fd_open: name Invoicing_xxxx.xls, flags = 00 mode = 0775, fd = 27. [2008/03/12 13:10:05, 2] smbd/open.c:open_file(391) Nathalie opened file Invoicing_xxxx.xls read=Yes write=No (numopen=2) [2008/03/12 13:10:05, 3] smbd/oplock_linux.c:linux_set_kernel_oplock(173) linux_set_kernel_oplock: Refused oplock on file Invoicing_xxxx.xls, fd = 27, dev = fd02, inode = 103023223. (Resource temporarily unavailable) [2008/03/12 13:10:05, 10] locking/locking.c:unparse_share_modes(665) unparse_share_modes: del: 0, tok = 0, num: 2 [2008/03/12 13:10:05, 10] locking/locking.c:print_share_mode_table(482) print_share_mode_table: share_mode_entry[0]: pid = 13174, share_access = 0x3, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x0, file_id = 11, uid = 1030, flags = 0, dev = 0xfd02, inode = 103023223 [2008/03/12 13:10:05, 10] locking/locking.c:print_share_mode_table(482) print_share_mode_table: share_mode_entry[1]: pid = 13174, share_access = 0x3, private_options = 0x200044, access_mask = 0x20089, mid = 0x0, type= 0x0, file_id = 13, uid = 1030, flags = 0, dev = 0xfd02, inode = 103023223 Note that the oplock can be granted or refused, but both times, the ultimate open succeeds and the file is opened in the application on the PC. Sometimes however, the open() fails and the user gets the error message "Access Denied" on his PC (this was with Excel 2007). The logs then show this sequence: [2008/03/12 13:11:48, 4] smbd/open.c:open_file_ntcreate(1605) calling open_file with flags=0x0 flags2=0x0 mode=0775, access_mask = 0x20089, open_access_mask = 0x20089 [2008/03/12 13:11:48, 10] smbd/open.c:fd_open(67) fd_open: name Invoicing_xxxx.xls, flags = 00 mode = 0775, fd = -1. Resource temporarily unavailable [2008/03/12 13:11:48, 3] smbd/open.c:open_file(301) Error opening file Invoicing_xxxx.xls (NT_STATUS_ACCESS_DENIED) (local_flags=0) (flags=0) [2008/03/12 13:11:48, 5] smbd/files.c:file_free(454) freed files structure 9418 (1 used) [2008/03/12 13:11:48, 3] smbd/error.c:error_packet_set(106) error packet at smbd/nttrans.c(817) cmd=162 (SMBntcreateX) NT_STATUS_ACCESS_DENIED It seems that there is some timing problem with oplocks. Resulting in the open failing (while in the other case the open succeeded, but the oplock was granted or refused in the step after it). For experimenting, I added "kernel oplock = no" to the smb.conf file. Since then I cannot reproduce the problem anymore (while I could reproduce it within 1 minute before). Is this an oplock problem in samba? Or linux kernel oplock problem? Or something completely different?
This very much seems to be a problem with kernel oplocks. Is this a pure Samba serving local file systems, or do you for example re-export an NFS import, or a GFS file system? What other applications are running on the box? Volker
It is indeed a local filesystem (ext3) that is shared by samba. No NFS involved (although the filesystem itself is exported by NFS as well, and can be accessed by some Linux workstations, although that is not the normal path of access to the files). The server is primarily a samba fileserver, running only a few scripts that manipulate some files in the tree on request. Simple perl scripts, no locking involved. (And the files where the problem manifests, are not under that categorie.) Since two weeks we also have another -- which I thought was unrelated -- weird problem on the same server: When saving a mail or an attachment from Thunderbird into the samba share, some people frequently get "File already exists", but they do not see it (can't be -- it was in a new folder they created). It seems however that Thunderbird on Windows always creates a 0-byte file, deletes it, and then prompts the user for the name to store. The 0-byte file exists only milliseconds at most. But it seems that here too, there is a some kind of timing problem or race condition, which results in the client seeing the presence of the file, while it should have been deleted already. It is an SMP kernel, so maybe I should investigate more in the Unix-kernel for race conditions or asynchronous events etc.