samba - Jun 2007 - 3.0.25a closing network drive connections?

Since upgrading from 3.0.24 to 3.0.25a this past weekend, network
drive connections are randomly being closed and immediately reopened.
This creates "Delayed write failed" errors for Firefox and
Thunderbird, various errors for Outlook with its PST files on network
drives, and errors from programs like InDesign that "The network
connection was lost for the file, or the file was modified by another
process."

I have a level 9 debug log from my computer when this happened.  (I
tried level 10 logs, but they ate up too much disk and rotated too
fast.)  Here are the relevant lines, from what I can tell:

[2007/06/07 10:54:46, 3] smbd/error.c:error_packet_set(106)
  error packet at smbd/notify.c(115) cmd=160 (SMBnttrans) NT_STATUS_OK
[2007/06/07 10:54:46, 5] lib/util.c:show_msg(484)
[2007/06/07 10:54:46, 5] lib/util.c:show_msg(494)
  size=71
  smb_com=0xa0
  smb_rcls=0
  smb_reh=0
  smb_err=0
  smb_flg=136
  smb_flg2=51201
  smb_tid=7
  smb_pid=3292
  smb_uid=101
  smb_mid=62151
  smt_wct=18
  smb_vwv[ 0]=    0 (0x0)
  smb_vwv[ 1]=    0 (0x0)
  smb_vwv[ 2]=    0 (0x0)
  smb_vwv[ 3]=    0 (0x0)
  smb_vwv[ 4]=    0 (0x0)
  smb_vwv[ 5]=    0 (0x0)
  smb_vwv[ 6]=    0 (0x0)
  smb_vwv[ 7]=    0 (0x0)
  smb_vwv[ 8]=    0 (0x0)
  smb_vwv[ 9]=    0 (0x0)
  smb_vwv[10]=    0 (0x0)
  smb_vwv[11]=    0 (0x0)
  smb_vwv[12]=    0 (0x0)
  smb_vwv[13]=    0 (0x0)
  smb_vwv[14]=    0 (0x0)
  smb_vwv[15]=    0 (0x0)
  smb_vwv[16]=    0 (0x0)
  smb_vwv[17]=    0 (0x0)
  smb_bcc=0
[2007/06/07 10:54:46, 3] smbd/process.c:timeout_processing(1328)
  timeout_processing: End of file from client (client has disconnected).
[2007/06/07 10:54:46, 5] lib/gencache.c:gencache_shutdown(94)
  Closing cache file
[2007/06/07 10:54:46, 5] libsmb/namecache.c:namecache_shutdown(79)
  namecache_shutdown: netbios namecache closed successfully.
[2007/06/07 10:54:46, 3] smbd/sec_ctx.c:set_sec_ctx(241)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2007/06/07 10:54:46, 5] auth/auth_util.c:debug_nt_user_token(448)
  NT user token: (NULL)
[2007/06/07 10:54:46, 5] auth/auth_util.c:debug_unix_user_token(474)
  UNIX token of user 0
  Primary group is 0 and contains 0 supplementary groups
[2007/06/07 10:54:46, 5] smbd/uid.c:change_to_root_user(288)
  change_to_root_user: now uid=(0,0) gid=(0,0)
[2007/06/07 10:54:46, 2] smbd/close.c:close_normal_file(399)
  josh closed file Downloads/SysInternals/psexec.exe (numopen=2) NT_STATUS_OK
[2007/06/07 10:54:46, 5] smbd/files.c:file_free(451)
  freed files structure 11353 (2 used)
[2007/06/07 10:54:46, 5] smbd/files.c:file_free(451)
  freed files structure 11191 (1 used)
[2007/06/07 10:54:46, 5] smbd/files.c:file_free(451)
  freed files structure 11076 (0 used)
[2007/06/07 10:54:46, 3] smbd/sec_ctx.c:set_sec_ctx(241)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2007/06/07 10:54:46, 5] auth/auth_util.c:debug_nt_user_token(448)
  NT user token: (NULL)
[2007/06/07 10:54:46, 5] auth/auth_util.c:debug_unix_user_token(474)
  UNIX token of user 0
  Primary group is 0 and contains 0 supplementary groups
[2007/06/07 10:54:46, 5] smbd/uid.c:change_to_root_user(288)
  change_to_root_user: now uid=(0,0) gid=(0,0)
[2007/06/07 10:54:46, 1] smbd/service.c:close_cnum(1230)
  pccomp8 (192.168.155.253) closed connection to service software

At the same time when we upgraded Samba, we rearranged some servers
and added a network switch.  So it's possible that this problem is
network related, but I don't think that it is; none of our switches
are reporting any packet errors, for example.

Any ideas or advice?

Thanks.

Josh Kelley

On 6/7/07, Josh Kelley <joshkel@gmail.com> wrote:
> Since upgrading from 3.0.24 to 3.0.25a this past weekend, network
> drive connections are randomly being closed and immediately reopened.
> This creates "Delayed write failed" errors for Firefox and
> Thunderbird, various errors for Outlook with its PST files on network
> drives, and errors from programs like InDesign that "The network
> connection was lost for the file, or the file was modified by another
> process."
>
> I have a level 9 debug log from my computer when this happened.  (I
> tried level 10 logs, but they ate up too much disk and rotated too
> fast.)  Here are the relevant lines, from what I can tell:
I've done some more investigating and managed to get a couple of level
10 debug logs from affected clients.  I had originally wondered if
this might be a networking issue, but I'm now pretty certain that it's
a Samba issue.  Each time the problem happens, from what I can tell
from looking at the logs, the server sends the client a message as
usual (reply_ntcreate_and_X in two instances, reply_ntcreate_and_X
then call_nt_transact_notify_change (?) in another), then it tries and
fails to read the next message:

[2007/06/08 14:02:21, 10] lib/util_sock.c:read_data(525)
  read_data: read of 4 returned 0. Error = Success
[2007/06/08 14:02:21, 10] lib/util_sock.c:receive_smb_raw(672)
  receive_smb_raw: length < 0!
[2007/06/08 14:02:21, 3] smbd/process.c:timeout_processing(1328)
  timeout_processing: End of file from client (client has disconnected).

Is anyone else seeing similar problems?  Should I open a Bugzilla or
post the full debug logs here?

Josh Kelley