samba 2.2.0 & linux 2.4.3 oplock break error on local fs bug repo rt

[Venning, Roger]

Greetings to the developers & congrats on 2.2 release.

I have a redhat 7.0 box with 2.4.3 kernel retro-
fitted, running samba 2.2.0. It has the following
options in smb.conf:

   locking = yes
   oplocks = yes 
   level2 oplocks = yes 
   oplock break wait time = 10
   strict locking = no
   fake oplocks = no

The problem I observed was as follows: client copied
a bunch of files to a server share that was a local
ext2 filesystem. Part way through the copy it 'hung',
and after a timeout, the client decided it was no
longer connected to the server (or the network!).
Repeated attempts to continue the copy kept 'hanging'
at the same 7MB file. Client attempted to delete the
copy, same result.

Logged into the samba server, and had a 'look' at the
file (head file | less). Suddenly smb.log started
spitting out messages as found below, and then all of
a sudden, the file was successfully deleted (ie., it
dissappeared with no further interaction from client).

The 'oplock break wait time = 10' is a relic of me
trying to get samba 2.2.0alpha binary rpm to do
successful oplocking for W2K client as required by MS
Word for accessing files on NFSv3. I eventually decided
that this was not working due to the binary being
compiled for a non-2.4 linux kernel platform, but not
until after much hassle :-)

Roger.

PS. If I find this is reproducible, I can can gather more
detailed logging information.


[2001/04/23 12:14:18, 0]
smbd/oplock_linux.c:linux_oplock_receive_message(135)
  Invalid file descriptor 25 in kernel oplock break!
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(379)
  process_local_message: unknown UDP message command code (0) - ignoring.
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 30045, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 30045, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
  process_local_message: Received unsolicited break reply - dumping info.
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 30011, port
1095, dev = 306, inode = 52213
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
  process_local_message: unsolicited oplock break reply from pid 30045, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:18, 0] lib/util_sock.c:write_socket_data(542)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
  write_socket_data: write failure. Error = Broken pipe
  process_local_message: Received unsolicited break reply - dumping info.
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:18, 0] lib/util_sock.c:write_socket(566)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
  write_socket: Error writing 39 bytes to socket 12: ERRNO = Broken pipe
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
  process_local_message: unsolicited oplock break reply from pid 30045, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:18, 0] lib/util_sock.c:send_smb(753)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(357)
  Error writing 39 bytes to client. -1. Exiting
  process_local_message: Received unsolicited break reply - dumping info.
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:18, 0] smbd/oplock.c:process_local_message(372)
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
  process_local_message: unsolicited oplock break reply from pid 30045, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
  process_local_message: unsolicited oplock break reply from pid 30045, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(357)
  process_local_message: Received unsolicited break reply - dumping info.
[2001/04/23 12:14:19, 0] smbd/oplock.c:process_local_message(372)
  process_local_message: unsolicited oplock break reply from pid 29946, port
1095, dev = 306, inode = 52213


--
Roger Venning - Technologist - Telstra Research Laboratories

          For a successful technology, reality must take
          precendence over public relations, for Nature
          cannot be fooled.                 Richard Feynman