getent does not list passwd from AD on 11.1

[bittenoff]

It is the dreaded ship active directory astern... and I'm at wits end...

In the picture is a "wbinfo -u" that works fine, a "wbinfo -g" that works fine, "getent group" works fine but "getent passwd" does not.

All of these pass:

Code:

$ wbinfo -u | wc -l
	  56
$ wbinfo -g | wc -l
	  71
$ wbinfo -t
checking the trust secret for domain AD via RPC calls succeeded
$ wbinfo --ping-dc
checking the NETLOGON for domain[AD] dc connection to "adserver.local" succeeded
$ net cache list | egrep '^Key:.*2045' | wc -l
	   2
$ wbinfo --sid-to-uid S-1-5-21-2700000000-1860000000-2950000000-2000
2045
$ wbinfo --uid-to-sid 2045
S-1-5-21-2700000000-1860000000-2950000000-2000
$ wbinfo -u | grep 'AD\user' | wc -l
1
$ wbinfo -s S-1-5-21-2700000000-1860000000-2950000000-2000
AD\user 1
$ wbinfo --gid-info 9000
AD\group:x:9000:

This does not work:

Code:

$ wbinfo -i 'AD\user'
failed to call wbcGetpwnam: WBC_ERR_DOMAIN_NOT_FOUND
Could not get info for user AD\user
$ wbinfo --uid-info 2000
failed to call wbcGetpwnam: WBC_ERR_DOMAIN_NOT_FOUND
Could not get info for uid 2000

Steps I've tried:
* from the GUI:
- rebuild database
- enable/disable active directory/smb
* From the CLI:

Code:

# service samba_server stop
# net cache flush
# service ix-pre-samba start
# service samba_server start

- manually emptying /var/tmp/.cache/.samba/

Turning up debugging, log.winbindd shows this:

Code:

...
[2018/02/08 16:30:57.974986,  1, pid=46603, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:468(ndr_print_function_debug)
	   wbint_LookupSid: struct wbint_LookupSid
		  in: struct wbint_LookupSid
			  sid					  : *
				  sid					  : S-1-5-21-2700000000-1860000000-2950000000-2000
[2018/02/08 16:30:57.975051, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Schedule immediate event "tevent_req_trigger": 0x811ebd160
[2018/02/08 16:30:57.975076, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Run immediate event "tevent_req_trigger": 0x811ebd160
[2018/02/08 16:30:57.975103,  1, pid=46603, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:468(ndr_print_function_debug)
	   wbint_LookupSid: struct wbint_LookupSid
		  out: struct wbint_LookupSid
			  type					 : *
				  type					 : SID_NAME_USER (1)
			  domain				   : *
				  domain				   : *
					  domain				   : 'AD'
			  name					 : *
				  name					 : *
					  name					 : 'user'
			  result				   : NT_STATUS_OK
[2018/02/08 16:30:57.975220,  1, pid=46603, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:468(ndr_print_function_debug)
	   wbint_GetNssInfo: struct wbint_GetNssInfo
		  in: struct wbint_GetNssInfo
			  info					 : *
				  info: struct wbint_userinfo
					  domain_name			  : *
						  domain_name			  : 'AD'
					  acct_name				: *
						  acct_name				: 'user'
					  full_name				: NULL
					  homedir				  : *
						  homedir				  : '/home/%D/%U'
					  shell					: *
						  shell					: '/bin/sh'
					  uid					  : 0x00000000000007f5 (2037)
					  primary_gid			  : 0x00000000ffffffff (4294967295)
					  primary_group_name	   : NULL
					  user_sid				 : S-1-5-21-2700000000-1860000000-2950000000-2000
					  group_sid				: S-1-5-21-2700000000-1860000000-2950000000-513
[2018/02/08 16:30:57.975407, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Schedule immediate event "tevent_queue_immediate_trigger": 0x811e4df60
[2018/02/08 16:30:57.975431, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Run immediate event "tevent_queue_immediate_trigger": 0x811e4df60
[2018/02/08 16:30:57.975456, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Added timed event "tevent_req_timedout": 0x811e4e620
[2018/02/08 16:30:57.976044, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Destroying timer event 0x811e4e620 "tevent_req_timedout"
[2018/02/08 16:30:57.976083,  1, pid=46603, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:468(ndr_print_function_debug)
	   wbint_GetNssInfo: struct wbint_GetNssInfo
		  out: struct wbint_GetNssInfo
			  info					 : *
				  info: struct wbint_userinfo
					  domain_name			  : *
						  domain_name			  : 'AD'
					  acct_name				: *
						  acct_name				: 'user'
					  full_name				: NULL
					  homedir				  : *
						  homedir				  : '/home/%D/%U'
					  shell					: *
						  shell					: '/bin/sh'
					  uid					  : 0x00000000000007f5 (2037)
					  primary_gid			  : 0x00000000ffffffff (4294967295)
					  primary_group_name	   : NULL
					  user_sid				 : S-1-5-21-2700000000-1860000000-2950000000-2000
					  group_sid				: S-1-5-21-2700000000-1860000000-2950000000-513
			  result				   : NT_STATUS_OK
[2018/02/08 16:30:57.976291, 10, pid=46603, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/wb_sids2xids.c:113(wb_sids2xids_send)
  SID 0: S-1-5-21-2700000000-1860000000-2950000000-513
[2018/02/08 16:30:57.976323, 10, pid=46603, effective(0, 0), real(0, 0)] ../source3/lib/idmap_cache.c:56(idmap_cache_find_sid2unixid)
  Parsing value for key [IDMAP/SID2XID/S-1-5-21-2700000000-1860000000-2950000000-513]: value=[-1:N]
[2018/02/08 16:30:57.976344, 10, pid=46603, effective(0, 0), real(0, 0)] ../source3/lib/idmap_cache.c:75(idmap_cache_find_sid2unixid)
  Parsing value for key [IDMAP/SID2XID/S-1-5-21-2700000000-1860000000-2950000000-513]: id=[4294967295], endptr=[:N]
[2018/02/08 16:30:57.976365, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Schedule immediate event "tevent_req_trigger": 0x811ef3160
[2018/02/08 16:30:57.976388, 50, pid=46603, effective(0, 0), real(0, 0), class=tevent] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
  samba_tevent: Run immediate event "tevent_req_trigger": 0x811ef3160
[2018/02/08 16:30:57.976412,  5, pid=46603, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
  Could not convert sid S-1-5-21-2700000000-1860000000-2950000000-2000: NT_STATUS_NO_SUCH_USER
[2018/02/08 16:30:57.976437, 10, pid=46603, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:797(wb_request_done)
  wb_request_done[47514:GETPWUID]: NT_STATUS_NO_SUCH_USER

I suspect it is this "NT_STATUS_NO_SUCH_USER" that is part of the problem here.

Looking at the samba config:

Code:

# grep idmap /usr/local/etc/smb4.conf
	idmap config *: backend = tdb
	idmap config *: range = 90000001-100000000
	idmap config AD: backend = ad
	idmap config AD: range = 1000-90000000
	idmap config AD: schema mode = rfc2307

... the ID ranges are wide enough to allow the UID and it is the same as another FreeNAS 9 host that is working fine.

 

[bittenoff]

There are a pair of AD servers (redundancy), but there does not appear to be any way to control which "one" FreeNAS chooses to make the Kerberos admin/passwd server, so whilst /etc/krb5.conf is the same on both, /etc/directoryservice/ActiveDirectory/config is not.

e.g. from the server that works:

Code:

ad_dcname=adserver2:389
ad_dchost=adserver2
ad_dcport=389
ad_gcname=adserver1:3268
ad_gchost=adserver1
ad_gcport=3268
ad_krbname=adserver1:88
ad_krbhost=adserver1
ad_krbport=88
ad_kpwdname=adserver2:464
ad_kpwdhost=adserver2
ad_kpwdport=464

and the one that does not:

Code:

ad_dcname=adserver1:389
ad_dchost=adserver1
ad_dcport=389
ad_gcname=adserver1:3268
ad_gchost=adserver1
ad_gcport=3268
ad_krbname=adserver2:88
ad_krbhost=adserver2
ad_krbport=88
ad_kpwdname=adserver1:464
ad_kpwdhost=adserver1
ad_kpwdport=464

but I think this is irrelevant as Active Directory should handle the redundancy automatically and using either one should be fine.

Looking at LDAP in /var/log/debug.log:

Code:

[common.freenasldap:2645] FreeNAS_ActiveDirectory_Users.__get_users: enter
[common.freenasldap:1151] FreeNAS_ActiveDirectory_Base.get_SRV_records: looking up SRV records for _ldap._tcp.dc._msdcs.ad....
[common.freenasldap:2695] FreeNAS_ActiveDirectory_Users.__get_users: AD [AD] users not in cache
[common.freenasldap:2173] FreeNAS_ActiveDirectory_Base.get_users: enter
[common.freenasldap:369] FreeNAS_LDAP_Directory._search: enter
[common.freenasldap:372] FreeNAS_LDAP_Directory._search: basedn = 'DC=ad,DC=...', filter = '(&(|(object
[common.freenasldap:404] FreeNAS_LDAP_Directory._search: pagesize = 1024
[common.freenasldap:411] FreeNAS_LDAP_Directory._search: getting page 0
[common.freenasldap:478] FreeNAS_LDAP_Directory._search: 117 results
[common.freenasldap:479] FreeNAS_LDAP_Directory._search: leave
[common.freenasldap:2197] FreeNAS_ActiveDirectory_Base.get_users: leave
...
[common.freenasldap:2721] Error on getpwnam: 'getpwnam(): name not found: AD\\user'

I've tried adding "debug" to all of the "winbind" entries in /etc/pam.d but nothing comes of that which I can see.

 

[hmeij]

Did you solve this? I seem to have stumbled in this same getpwnam error in v11.1. From a plain limux server using smbclient I can query the freenas server and my AD credentials are ok, when I map from windows desktop client they are not.

Any significance to that double slash in what is returned as object 'AD\\user'?

-Henk

 

[CuthbertRumbold]

What resolved this issue for me (after much consternation) was to add these two Samba directives to "Auxiliary parameters" under SMB settings:

Code:

idmap config MYACTUALDOMAIN: unix_primary_group = yes
idmap config MYACTUALDOMAIN: unix_nss_info = yes

This tells winbind to
1) use the primary group that AD returns from the users (RFC2307) gidNumber attribute, rather than using "Domain Users", and
2) (optional) use the loginShell and unixHomeDirectory attrs as well.

Reference: https://www.samba.org/samba/history/samba-4.6.0.html - search for "winbind primary group and nss info"

Cheers,
Roy

 

[hmeij]

Excellent dig! Those options seem to be part of idmap_ad
https://www.samba.org/samba/docs/current/man-html/idmap_ad.8.html

So I'll test that. Here is my experience so far with 11.1-U1
test1 idmap = rid, no nss info gave me arbitrary uid/gid, consistent but arbitrary, as expected
test2 idmap = ad, nss = rfc2307 gave me uid/gid from AD...this is what we want
however clicking on Change Permissions for Dataset caused the GUI to hang 15+ mins (see thread)
repeatable with a rebuild test env and reboots, uwsgi in a loop
test3 idmap = rid, no nss ... to my surprise uid/gid from AD showed up now, some trigger from AD?
this is an iffy "will it work?" to adopt for a production environment

Going back to test2 and see if these idmap config options fix the GUI problem. The uid/gid do load into cache so I'm not super hopeful ...

-Henk

 

[hmeij]

Long story short; it's the cache acting in unexpected ways. Clear it and reboot to really assess config changes. A reboot will not clear the cache as you'd expect (it's mouted in /var which is tmpfs but comes from my first volume). Worse, Directory > AD > Rebuild also will not clear cache and does not reload object from AD that are already in cache (that is a change uid/gid in AD does not update in cache).

Hyjacking Roy's thread here because it has lots of good debug info. Here is what I ended up doing which seems to give me a robust test environment. Our AD is screwed up so your mileage may vary, we seem to have both wesleyan.edu and wesad.wesleyan.edu as realms, trees whatever...confusing domain and realm..

Top panel Directory > AD
Real-name enter your_realm-name
check unix extensions
uncheck allow trusted domains
uncheck use default domain
uncheck allow dns updates
uncheck disable AD cache (did not test this, definitely want a cache with the size of our AD)
specify user/group base (you can use the builtin defaults Users and Groups)
domain controller provide FQDN of a dc
idmap = ad (edit ranges for your site)
winbind nss = rfc2307
then Save (make sure kerberos realm is set to your_realm_name after this, or select, then save)

Top panel Directory > AD
edit Kerberos Realm tab (add FQDN of same server for kdc),save
edit Kerberos Settings tab (in libdefaults add...), save
default_realm = your_realm_name
dns_lookup_realm = false
dns_lookup_kdc = true

Left panel, Services > SMB
workgroup = WORKGROUP
in auxiliary parms box (add, then save...note your_realm_name and your_domain_name are likely different...save)
idmap config your_domain_name: unix_primary_group = yes
idmap config your_domain_name: unix_nss_info = yes
idmap_ldb use:rfc2307 = Yes

That last line tells samba if no unix AD extensions (range specific) are found go to AD first for that object. That updates the cache without having to do a rebuild and avoids a collision of uid/gid between AD and Freenas behavior (at least in my tests).

Now, get a clean environment, this took me weeks to understand, go to shell, and force a clean cache build ...

net cache flush; net cache list
reboot

Stable, but not yet usable in production. When applying dataset permissions the gui displays "loading..." in debug.log all objects spool by with no unix extensions (get[pw|gr|nam errors, this in my case takes 10 mins. So unless I can not filter those objects out during cache build this is a major problem.

-Henk