samba - Oct 2007 - long delay when connecting to samba server

Hi all,

I am experiencing a long delay when connecting from a windows machine  
to my samba server.  All the details of my setup are below.  Here are  
the characteristics of the problem:

client (windows xp desktop) browses to domain in Network Places.
samba server appears as expected.
double-clicking on the samba server causes a delay of approximately  
one minute before share drives are listed.
Once the shares are listed, browsing is very fast.

I am VERY confused by this behavior.  I need to resolve it quickly.   
My users are revolting!

What might cause such a huge delay in accessing Samba?

My env uses an Active Directory server for authentication, and so I  
am running smbd, nmbd, and winbindd.  I have cranked up the log level  
to see a lot of action in the log files.  I attempted a connection on  
2007/10/30 at 10:32:07.  At 10:33:22, the share drives were listed in  
my windows desktop.  Delays of 1 minute (at a minimum) are common and  
reproduceable.

My client IP address is 10.1.1.233.  The server IP address is  
10.1.1.14.  The domain name is 60framescorp.  My username is dviner.

Here's what I see in the relevant logs:

[captured on public doc because it's quite long]
http://docs.google.com/Doc?id=ddpkhpb5_49c4rkfs

======================================================================== 
=========================ENVIRONMENT:
Samba server
	- version 3.0.26a
	- running CentOS 5.0
Samba configuration (smb.conf) global section:
    workgroup = 60framescorp
    server string = Shared Drives (Samba Server %v)
    security = domain

     # required for AD domain
    encrypt passwords = yes
    allow trusted domains = no
    idmap uid = 200000 - 300000
    idmap gid = 200000 - 300000
    winbind nested groups = yes

     # this tells Samba to use a separate log file for each machine
     # that connects (%m = user, %S = share)

    #log file = /usr/local/samba/var/log.%m
    log file = /usr/local/samba/var/log.%S
    log level = 4 auth:10 winbind:3

     # Put a capping on the size of the log files (in Kb).
    max log size = 1000

    local master = no
    dns proxy = no

In pouring through my log files, it looks to me like the client times  
out its connection.  In log.%S, I notice this entry:


[2007/10/30 10:32:07, 3] smbd/service.c:make_connection_snum(1033)
   coppola (10.1.1.233) connect to service IPC$ initially as user  
60FRAMESCORP\dviner (uid=200000, gid=200000) (pid 28765
)
[2007/10/30 10:32:07, 3] smbd/sec_ctx.c:set_sec_ctx(241)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2007/10/30 10:32:07, 3] smbd/reply.c:reply_tcon_and_X(574)
   tconX service=IPC$

.. delay of 70 seconds ...

[2007/10/30 10:33:22, 0] lib/util_sock.c:read_data(534)
   read_data: read failure for 4 bytes to client 10.1.1.233. Error =  
Connection reset by peer
[2007/10/30 10:33:22, 3] smbd/process.c:timeout_processing(1334)
   timeout_processing: receive_smb error (Connection reset by peer)  
Exiting
[2007/10/30 10:33:22, 3] smbd/sec_ctx.c:set_sec_ctx(241)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2007/10/30 10:33:22, 4] smbd/vfs.c:vfs_ChDir(665)
   vfs_ChDir to /tmp


the odd thing is that the connection the second time works fine.  
here's the snippet surrounding the reply_tcon_and_X message:

[2007/10/30 10:33:22, 3] smbd/sec_ctx.c:set_sec_ctx(241)
   setting sec ctx (200000, 200000) - sec_ctx_stack_ndx = 0
[2007/10/30 10:33:22, 3] smbd/service.c:make_connection_snum(1033)
   coppola (10.1.1.233) connect to service IPC$ initially as user  
60FRAMESCORP\dviner (uid=200000, gid=200000) (pid 29044
)
[2007/10/30 10:33:22, 3] smbd/sec_ctx.c:set_sec_ctx(241)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2007/10/30 10:33:22, 3] smbd/reply.c:reply_tcon_and_X(574)
   tconX service=IPC$
[2007/10/30 10:33:22, 3] smbd/process.c:process_smb(1068)
   Transaction 4 of length 104
[2007/10/30 10:33:22, 3] smbd/process.c:switch_message(926)
   switch message SMBntcreateX (pid 29044) conn 0x9261dc0


What would cause the first reply_tcon_and_X to timeout but the second  
to succeed immediately?  There is no significant traffic on the  
network at all.

Any thoughts on how to debug this further or how to fix it?

thanks
dave

On Oct 30, 2007, at 11:18 AM, Dave Viner wrote:
> Hi all,
>
> I am experiencing a long delay when connecting from a windows  
> machine to my samba server.  All the details of my setup are  
> below.  Here are the characteristics of the problem:
>
> client (windows xp desktop) browses to domain in Network Places.
> samba server appears as expected.
> double-clicking on the samba server causes a delay of approximately  
> one minute before share drives are listed.
> Once the shares are listed, browsing is very fast.
>
> I am VERY confused by this behavior.  I need to resolve it  
> quickly.  My users are revolting!
>
> What might cause such a huge delay in accessing Samba?
>
> My env uses an Active Directory server for authentication, and so I  
> am running smbd, nmbd, and winbindd.  I have cranked up the log  
> level to see a lot of action in the log files.  I attempted a  
> connection on 2007/10/30 at 10:32:07.  At 10:33:22, the share  
> drives were listed in my windows desktop.  Delays of 1 minute (at a  
> minimum) are common and reproduceable.
>
> My client IP address is 10.1.1.233.  The server IP address is  
> 10.1.1.14.  The domain name is 60framescorp.  My username is dviner.
>
> Here's what I see in the relevant logs:
>
> [captured on public doc because it's quite long]
> http://docs.google.com/Doc?id=ddpkhpb5_49c4rkfs