Bug 4883 - Blocking SMBreadX when accessing Windows Server 2003 R2 Shares from a Samba Domain
Blocking SMBreadX when accessing Windows Server 2003 R2 Shares from a Samba D...
Status: RESOLVED INVALID
Product: Samba 3.0
Classification: Unclassified
Component: Domain Control
3.0.25b
Other Linux
: P3 normal
: none
Assigned To: Samba Bugzilla Account
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2007-08-15 03:37 UTC by Patrick Rynhart
Modified: 2007-08-16 05:25 UTC (History)
0 users

See Also:


Attachments
Debug level 10 logs (162.31 KB, application/octet-stream)
2007-08-16 03:52 UTC, Patrick Rynhart
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Patrick Rynhart 2007-08-15 03:37:48 UTC
I have a Samba 3.0.25b Domain in a one way trust relationship with a Windows Server 2003 DC such that Samba is the Trusting Domain.  Denote the primary (Samba domain) by SAMBA and the trusted Windows domain by WINDOWS.  The SAMBA domain includes Member Servers running Windows Server 2003 R2.

When WINDOWS users log on interactively to a SAMBA Workstation and access shares on the W2K3 Member Servers, a 20 second timeout/delay occurs upon the initial connection attempt UNLESS the UNC path also contains a trailing backslash.  To reproduce the fault from a SAMBA Workstation: Start -> Run, enter a UNC path without a trailing backslash, e.g. \\SERVER1\Shared or \\SERVER1\C$. (Note: The interactive user must be from a trusted domain; the delay does not occur for SAMBA users.)

The pattern observed in terms of SMB messages is 
SMBnegprot, SMBsesssetupX, SMBtconX, SMBntcreateX, SMBwriteX, SMBreadX, SMBwriteX, 
SMBreadX, [20 SECOND DELAY], SMBwriteX, SMBreadX

Example:

log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBnegprot (pid 7941) conn 0x0
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBsesssetupX (pid 7941) conn 0x0
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBsesssetupX (pid 7941) conn 0x0
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBtconX (pid 7941) conn 0x0
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBntcreateX (pid 7941) conn 0x803db258
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBwriteX (pid 7941) conn 0x803db258
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBreadX (pid 7941) conn 0x803db258
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBwriteX (pid 7941) conn 0x803db258
log.SERVER1:[2007/08/14 19:59:16, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBreadX (pid 7941) conn 0x803db258
log.SERVER1:[2007/08/14 19:59:37, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBwriteX (pid 7941) conn 0x803db258
log.SERVER1:[2007/08/14 19:59:37, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBreadX (pid 7941) conn 0x803db258

After the initial connection the delay does not occur again provided that the User reconnects to the same share within a certain period of time.  In other words, if the share has been previously enumerated the delay does not occur (for that client only).

The delay on the initial connection attempt does not occur if the UNC path contains a trailing backslash.  However, when a User goes Start -> Run and enters \\SERVER1\Share\, e.g., the contents of the Share are immediately enumerated (i.e. they appear as a drop down menu within the Run box).  When the User then clicks OK the share is therefore presented immediately.

In this case, the pattern in terms of SMB messages seen is SMBnegprot, SMBsesssetupX, SMBtconX, SMBntcreateX, SMBwriteX, SMBreadX, SMBwriteX, SMBreadX

Example:

log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBnegprot (pid 7920) conn 0x0
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBsesssetupX (pid 7920) conn 0x0
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBsesssetupX (pid 7920) conn 0x0
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBtconX (pid 7920) conn 0x0
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBntcreateX (pid 7920) conn 0x803db258
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBwriteX (pid 7920) conn 0x803db258
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBreadX (pid 7920) conn 0x803db258
log.SERVER1:[2007/08/14 19:57:06, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBwriteX (pid 7920) conn 0x803db258
log.SERVER1:[2007/08/14 19:57:07, 0] smbd/process.c:switch_message(927)
log.SERVER1:  switch message SMBreadX (pid 7920) conn 0x803db258

Regards,

Patrick
Comment 1 Volker Lendecke 2007-08-15 05:09:00 UTC
Please provide a debug level 10 log of smbd of this, with 'debug hires timestamp = yes' being set.

Volker
Comment 2 Patrick Rynhart 2007-08-16 03:52:23 UTC
Created attachment 2868 [details]
Debug level 10 logs

The requested debug level 10 logs are attached.  The archive contents are:

log.ist-dc1, Samba 3.0.25b PDC
log.ist-staff, Member Server running Windows Server 2003 R2
log.nmbd
log.smbd
log.winbindd

The delay occurs between 20:34:30 and 20:34:51

Regards,

Patrick
Comment 3 Volker Lendecke 2007-08-16 05:25:59 UTC
There's nothing strange in the logfiles during that time. So I would assume that it's something that is happening on the members or the w2k3 box. You need to look with a sniffer what's going on. I'm closing this as invalid, I don't see a Samba bug here.