[Samba] Intermittent failure

Andrea Venturoli ml at netfence.it
Wed May 14 02:27:24 MDT 2014


Hello.

I'm in need of some help to shed some light on a strange problem.

The box is running Samba 4.1.7 on FreeBSD 9.2/amd64 and I suspect 
(though I'm not sure) all troubles started after the upgrade from 4.1.6.
The setup is quite simple: no AD, no LDAP, only one server.

A command as simple as "smbclient -U user //SERVER/SHARE", if fired up 
several times in a row on the server itself, will sometimes succeed, 
somtimes fail.
Same happens for "smbclient -U root -L //SERVER".


A sample log:
> smbclient -d 5 -U xxxxxx //XXXXX/xxxxxxxxxxx
> INFO: Current debug levels:
>   all: 5
>   tdb: 5
>   printdrivers: 5
>   lanman: 5
>   smb: 5
>   rpc_parse: 5
>   rpc_srv: 5
>   rpc_cli: 5
>   passdb: 5
>   sam: 5
>   auth: 5
>   winbind: 5
>   vfs: 5
>   idmap: 5
>   quota: 5
>   acls: 5
>   locking: 5
>   msdfs: 5
>   dmapi: 5
>   registry: 5
>   scavenger: 5
>   dns: 5
>   ldb: 5
> lp_load_ex: refreshing parameters
> Initialising global parameters
> max_open_files: increasing sysctl_max (11095) to minimum Windows limit (16384)
> rlimit_max: increasing rlimit_max (11095) to minimum Windows limit (16384)
> INFO: Current debug levels:
>   all: 5
>   tdb: 5
>   printdrivers: 5
>   lanman: 5
>   smb: 5
>   rpc_parse: 5
>   rpc_srv: 5
>   rpc_cli: 5
>   passdb: 5
>   sam: 5
>   auth: 5
>   winbind: 5
>   vfs: 5
>   idmap: 5
>   quota: 5
>   acls: 5
>   locking: 5
>   msdfs: 5
>   dmapi: 5
>   registry: 5
>   scavenger: 5
>   dns: 5
>   ldb: 5
> params.c:OpenConfFile() - Unable to open configuration file "/usr/local/etc/smb4.conf":
> 	Permission denied
> pm_process() returned No
> smbclient: Can't load /usr/local/etc/smb4.conf - run testparm to debug it
> added interface re0 ip=192.168.1.254 bcast=192.168.1.255 netmask=255.255.255.0
> added interface re1 ip=192.168.111.1 bcast=192.168.111.255 netmask=255.255.255.0
> Netbios name list:-
> my_netbios_names[0]="XXXXX"
> Client started (version 4.1.7).
> Enter xxxxxx's password:
> Opening cache file at /var/db/samba4/gencache.tdb
> tdb(/var/db/samba4/gencache.tdb): tdb_open_ex: could not open file /var/db/samba4/gencache.tdb: Permission denied
> gencache_init: Opening cache file /var/db/samba4/gencache.tdb read-only.
> Opening cache file at /var/db/samba4/gencache_notrans.tdb
> sitename_fetch: No stored sitename for
> no entry for XXXXX#20 found.
> resolve_lmhosts: Attempting lmhosts lookup for name XXXXX<0x20>
> resolve_lmhosts: Attempting lmhosts lookup for name XXXXX<0x20>
> startlmhosts: Can't open lmhosts file /usr/local/etc/lmhosts. Error was No such file or directory
> resolve_wins: WINS server resolution selected and no WINS servers listed.
> resolve_hosts: Attempting host lookup for name XXXXX<0x20>
> namecache_store: storing 1 address for XXXXX#20: 192.168.111.1
> Connecting to 192.168.111.1 at port 445
> Socket options:
> 	SO_KEEPALIVE = 0
> 	SO_REUSEADDR = 0
> 	SO_BROADCAST = 0
> 	TCP_NODELAY = 4
> 	Could not test socket option TCP_KEEPCNT.
> 	Could not test socket option TCP_KEEPIDLE.
> 	Could not test socket option TCP_KEEPINTVL.
> 	IPTOS_LOWDELAY = 0
> 	IPTOS_THROUGHPUT = 0
> 	SO_REUSEPORT = 0
> 	SO_SNDBUF = 48996
> 	SO_RCVBUF = 81660
> 	SO_SNDLOWAT = 2048
> 	SO_RCVLOWAT = 1
> 	SO_SNDTIMEO = 0
> 	SO_RCVTIMEO = 0
>  session request ok
> Doing spnego session setup (blob length=74)
> got OID=1.3.6.1.4.1.311.2.2.10
> got principal=not_defined_in_RFC4178 at please_ignore
> Got challenge flags:
> Got NTLMSSP neg_flags=0x60898215
>   NTLMSSP_NEGOTIATE_UNICODE
>   NTLMSSP_REQUEST_TARGET
>   NTLMSSP_NEGOTIATE_SIGN
>   NTLMSSP_NEGOTIATE_NTLM
>   NTLMSSP_NEGOTIATE_ALWAYS_SIGN
>   NTLMSSP_NEGOTIATE_NTLM2
>   NTLMSSP_NEGOTIATE_TARGET_INFO
>   NTLMSSP_NEGOTIATE_128
>   NTLMSSP_NEGOTIATE_KEY_EXCH
> NTLMSSP: Set final flags:
> Got NTLMSSP neg_flags=0x60088215
>   NTLMSSP_NEGOTIATE_UNICODE
>   NTLMSSP_REQUEST_TARGET
>   NTLMSSP_NEGOTIATE_SIGN
>   NTLMSSP_NEGOTIATE_NTLM
>   NTLMSSP_NEGOTIATE_ALWAYS_SIGN
>   NTLMSSP_NEGOTIATE_NTLM2
>   NTLMSSP_NEGOTIATE_128
>   NTLMSSP_NEGOTIATE_KEY_EXCH
> NTLMSSP Sign/Seal - Initialising with flags:
> Got NTLMSSP neg_flags=0x60088215
>   NTLMSSP_NEGOTIATE_UNICODE
>   NTLMSSP_REQUEST_TARGET
>   NTLMSSP_NEGOTIATE_SIGN
>   NTLMSSP_NEGOTIATE_NTLM
>   NTLMSSP_NEGOTIATE_ALWAYS_SIGN
>   NTLMSSP_NEGOTIATE_NTLM2
>   NTLMSSP_NEGOTIATE_128
>   NTLMSSP_NEGOTIATE_KEY_EXCH
> SPNEGO login failed: Undetermined error
> session setup failed: NT_STATUS_UNSUCCESSFUL



At the same time log.smbd shows:
> [2014/05/14 10:18:19.719746,  2] ../source3/param/loadparm.c:535(max_open_files)
>   max_open_files: increasing sysctl_max (11095) to minimum Windows limit (16384)
> [2014/05/14 10:18:19.719851,  2] ../source3/param/loadparm.c:543(max_open_files)
>   rlimit_max: increasing rlimit_max (11095) to minimum Windows limit (16384)
> [2014/05/14 10:18:19.720670,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxx]"
> [2014/05/14 10:18:19.720756,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxx]"
> [2014/05/14 10:18:19.720951,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxx]"
> [2014/05/14 10:18:19.721046,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxx]"
> [2014/05/14 10:18:19.721229,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxxxxx]"
> [2014/05/14 10:18:19.721334,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxxxx]"
> [2014/05/14 10:18:19.721465,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxx]"
> [2014/05/14 10:18:19.721596,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxx]"
> [2014/05/14 10:18:19.721737,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxxx]"
> [2014/05/14 10:18:19.721890,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxxxx]"
> [2014/05/14 10:18:19.722042,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxxx]"
> [2014/05/14 10:18:19.722151,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxxxxxx]"
> [2014/05/14 10:18:19.722283,  2] ../source3/param/loadparm.c:3581(do_section)
>   Processing section "[xxxxxxx]"
> [2014/05/14 10:18:19.729397,  2] ../source3/auth/auth.c:278(auth_check_ntlm_password)
>   check_ntlm_password:  authentication for user [xxxxxx] -> [xxxxxx] -> [xxxxxx succeeded
> [2014/05/14 10:18:19.732064,  1] ../source3/auth/token_util.c:430(add_local_groups)
>   SID S-1-5-21-XXXXXXXXXX-XXXXXXXXXX-XXXXXXXXXX-XXXX -> getpwuid(4294967295) failed
> [2014/05/14 10:18:19.732157,  1] ../source3/smbd/sesssetup.c:276(reply_sesssetup_and_X_spnego)
>   Failed to generate session_info (user and group token) for session setup: NT_STATUS_UNSUCCESSFUL



While I'm no expert, the last lines are quite suspicious to me: 
authentication succeeds, but somehow that's not enough.
I searched for "SID -> getpwuid failed" but came up with nothing.



Relevant part of smb4.conf:
> [global]
>         workgroup = XXXXXXX
>         netbios aliases=SERVER
>         server string = NetFence
>         interfaces = re1
>         hosts allow = 127. 192.168.111.0/24 10.1.2.15
>         security = user
>         encrypt passwords = yes
>         os level = 255
>         local master = yes
>         domain master = yes
>         preferred master = yes
>         domain logons = yes
>         wins support = yes
>         wins proxy = yes
>         dns proxy = yes
>         name resolve order = wins
>         logon script=netlogon.cmd
>         time server = Yes
>         map archive = No



Any hint on where I should go and look next?



  bye & Thanks
	av.


More information about the samba mailing list