Weird Samba issues

Thu Dec 15 07:03:12 MST 2011

I manage a Samba server that has been working nicely for a couple of 
months (after it replace the old Samba server which worked happily for 
years). We use LDAP for accounts, but don't use domain logons or 
anything fancy.

All users have their home dir on Samba mapped to drive 'M:'. In their 
home, there are symbolic links to various directories they're entitled 
to access. Links and file-system permissions are periodically maintained 
by a shell script based on user's groups (fetched from nsswitch) and 
this worked well with the old server and it seemed to work well for a 
couple of months now.

Generally users only use the 'homes' share, while admins use some 
additional shares like 'backup'.

About a week or two ago users started reporting their 'Explorer' windows 
are freezing while using the share and things seem to be getting worse 
(more and more users complain).

So I did a bit of testing on my own and can indeed confirm that while 
browsing the directories on the 'M:' drive, the 'Explorer' window 
sometimes becomes unresponsive - if I let it be for long enough it then 
reports an error:

> 'An error occurred while reconnecting M: to \\mdisk\user1
> Microsoft Windows Network : The local device name is already in use
> This connection has not been restored'

While waiting, I'm able to fire up another Explorer window and browse 
those same directories with no issues, unless it -seemingly randomly- 
happens on that windows too, but I can then open a third windows and 
work there. Of course users are not happy with that 'solution'.

Looking at the workstation log file there are no obvious errors. The 
only thing that is a bit odd are lines like ths:

> [2011/12/15 14:18:04.263224,  2] passdb/pdb_ldap.c:572(init_sam_from_ldap)
>   init_sam_from_ldap: Entry found for user: user9
> [2011/12/15 14:19:18.083636,  2] passdb/pdb_ldap.c:572(init_sam_from_ldap)
>   init_sam_from_ldap: Entry found for user: user3
> ....
>

Where 'user3' and 'user9' are NOT the username I'm really logged in with 
(and it's not limited to just those two users).

Looking at 'nmbd' log file, this is what it looks like after restarting it:

> [2011/12/15 14:39:52,  0] nmbd/nmbd.c:857(main)
>   nmbd version 3.5.4-5.11.1-2573-SUSE-SL11.3 started.
>   Copyright Andrew Tridgell and the Samba Team 1992-2010
> [2011/12/15 14:39:52.978706,  2] 
> lib/tallocmsg.c:106(register_msg_pool_usage)
>   Registered MSG_REQ_POOL_USAGE
> [2011/12/15 14:39:52.978746,  2] 
> lib/dmallocmsg.c:77(register_dmalloc_msgs)
>   Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
> [2011/12/15 14:39:52.978908,  2] param/loadparm.c:7296(handle_include)
>   Can't find include file /etc/samba/dhcp.conf
> [2011/12/15 14:39:52.979316,  2] nmbd/nmbd.c:890(main)
>   Becoming a daemon.
> [2011/12/15 14:39:52.980906,  0] nmbd/asyncdns.c:155(start_async_dns)
>   started asyncdns process 25834
> [2011/12/15 14:39:52.982597,  2] lib/interface.c:478(interpret_interface)
>   interpret_interface: Adding interface 192.168.1.3/17
> [2011/12/15 14:39:52.982637,  2] lib/interface.c:340(add_interface)
>   added interface 192.168.1.3/17 ip=192.168.1.3 bcast=192.168.127.255 
> netmask=255.255.128.0
> [2011/12/15 14:39:52.982738,  2] lib/interface.c:340(add_interface)
>   added interface lo ip=127.0.0.1 bcast=127.255.255.255 netmask=255.0.0.0
> [2011/12/15 14:39:52.982779,  2] nmbd/nmbd_subnetdb.c:299(create_subnets)
>   create_subnets: Ignoring loopback interface.
> [2011/12/15 14:39:52.982905,  2] nmbd/nmbd_subnetdb.c:171(make_subnet)
>   making subnet name:192.168.1.3 Broadcast address:192.168.127.255 
> Subnet mask:255.255.128.0
> [2011/12/15 14:39:52.982938,  2] nmbd/nmbd_subnetdb.c:171(make_subnet)
>   making subnet name:UNICAST_SUBNET Broadcast address:127.0.0.1 Subnet 
> mask:127.0.0.1
> [2011/12/15 14:39:52.982966,  2] nmbd/nmbd_subnetdb.c:171(make_subnet)
>   making subnet name:REMOTE_BROADCAST_SUBNET Broadcast address:0.0.0.0 
> Subnet mask:0.0.0.0
> [2011/12/15 14:39:52.982994,  2] nmbd/nmbd_subnetdb.c:171(make_subnet)
>   making subnet name:WINS_SERVER_SUBNET Broadcast address:0.0.0.0 
> Subnet mask:0.0.0.0
> [2011/12/15 14:39:57.008772,  2] 
> nmbd/nmbd_elections.c:107(check_for_master_browser_fail)
>   check_for_master_browser_fail: Forcing election on workgroup ZAG 
> subnet 192.168.1.3
> [2011/12/15 14:39:59.436528,  2] 
> nmbd/nmbd_elections.c:40(send_election_dgram)
>   send_election_dgram: Sending election packet for workgroup ZAG on 
> subnet 192.168.1.3
> [2011/12/15 14:40:01.015802,  2] 
> nmbd/nmbd_elections.c:40(send_election_dgram)
>   send_election_dgram: Sending election packet for workgroup ZAG on 
> subnet 192.168.1.3
> [2011/12/15 14:40:03.018011,  2] 
> nmbd/nmbd_elections.c:40(send_election_dgram)
>   send_election_dgram: Sending election packet for workgroup ZAG on 
> subnet 192.168.1.3
> [2011/12/15 14:40:04.372942,  2] 
> nmbd/nmbd_elections.c:40(send_election_dgram)
>   send_election_dgram: Sending election packet for workgroup ZAG on 
> subnet 192.168.1.3
> [2011/12/15 14:40:07.059608,  2] 
> nmbd/nmbd_elections.c:40(send_election_dgram)
>   send_election_dgram: Sending election packet for workgroup ZAG on 
> subnet 192.168.1.3
> [2011/12/15 14:40:07.059731,  2] nmbd/nmbd_elections.c:200(run_elections)
>   run_elections: >>> Won election for workgroup ZAG on subnet 
> 192.168.1.3 <<<
> [2011/12/15 14:40:07.059786,  2] 
> nmbd/nmbd_become_lmb.c:536(become_local_master_browser)
>   become_local_master_browser: Starting to become a master browser for 
> workgroup ZAG on subnet 192.168.1.3
> [2011/12/15 14:40:15.612801,  0] 
> nmbd/nmbd_become_lmb.c:395(become_local_master_stage2)
>   *****
>
>   Samba name server NEON is now a local master browser for workgroup 
> ZAG on subnet 192.168.1.3
>
>   *****
> [2011/12/15 14:40:15.613124,  1] 
> nmbd/nmbd_incomingrequests.c:327(process_node_status_request)
>   process_node_status_request: status request for name ZAG<1b> from IP 
> 192.168.1.3 on subnet UNICAST_SUBNET - name not found.
> [2011/12/15 14:40:21.244704,  1] 
> nmbd/nmbd_incomingrequests.c:327(process_node_status_request)
>   process_node_status_request: status request for name ZAG<1b> from IP 
> 192.168.1.3 on subnet UNICAST_SUBNET - name not found.
> [2011/12/15 14:40:26.162337,  1] 
> nmbd/nmbd_incomingrequests.c:327(process_node_status_request)
>   process_node_status_request: status request for name ZAG<1b> from IP 
> 192.168.1.3 on subnet UNICAST_SUBNET - name not found.
> [2011/12/15 14:40:31.658050,  1] 
> nmbd/nmbd_incomingrequests.c:327(process_node_status_request)
>   process_node_status_request: status request for name ZAG<1b> from IP 
> 192.168.1.3 on subnet UNICAST_SUBNET - name not found.
> [2011/12/15 14:40:35.779190,  0] 
> nmbd/nmbd_browsesync.c:247(domain_master_node_status_fail)
>   domain_master_node_status_fail:
>   Doing a node status request to the domain master browser
>   for workgroup ZAG at IP 192.168.1.3 failed.
>   Cannot sync browser lists.

Where 'NEON' is the 'main' name of the server (it also has an alias 
MDISK), and 'ZAG' is the workgroup name.

Other 'workgroups' exist on the same TCP/IP network (192.168.1.3/17), 
but they say they don't have any servers - just XP and Windows 7 
desktops / workstations. They also say they haven't changed anything on 
their network in that recent time frame...

So I'm a bit lost here - what else can or should I check? What log-level 
should I increase to get relevant info, but not to over-clutter them?

Anything I can do on a Windows machine for testing?

Any ideas at all?

Best regards, Danilo