[Samba] File sharing is ok, but new ADS user validation is not ok

Wed Nov 19 19:59:06 GMT 2008

We have Samba 3.2.4 on two SLES 10 (one is SP1, the other SP2 64bit)
machines.  Both are member servers in our ADS, which was over the past
month given some additional DCs, new IPs for all DCs, and upgraded to
Windows 2008 (from win2003). The krb5.conf and nsswitch.conf files on
the two machines are identical; the smb.conf files are *nearly*
identical in their common section; the filewall rules for the two
machines are a little different -- both allow the MS file sharing and
rpc ports and do not restrict or allow particular IP ranges.  The
hosts and resolve files are also the same except for the machines' IP
and name.

Both Samba installs are successfully serving files using ADS
credentials from XP machines with file permissions assigned on raiser
file systems with ADS IDs.

But all is not well.  The SuSE SP2 64bit machine ("Bad Samba") will
not allow me to do commands like these:

wbinfo -i <ads id> or wbinfo -r <ads id)
response: could not get info / groups for ads user <ads id>

chown ADS+<ads id> somefile
response: CHOWN: 'ADS+<ads id>': invalid user

getent groups shows only local groups

wbinfo -g shows one locally defined group and the BUILTINs.

Also interesting, if Bad Samba already "knows" the ads user, then I
can assign file rights with chown.  Bad Samba used to be able to do
these tasks -- otherwise our existing file sharing couldn't now be
functioning -- but can't get new info from our ADS.  But it can serve
files.  There must be multiple ways in to the ADS used for some
different functional parts of the Samba world, I'd guess.

Samba versions are:

Good Samba: Version 3.2.4-0.1.130-1906-SUSE-SLES10
Bad Samba: Version 3.2.4-0.1.130-1906-SUSE-SLES10

It's likely the Kerberos versions are also very nearly identical.

The log files on Bad Samba have many complaints about resolving KDC
for realm and the like.  The krb5.conf files are minimal, since I
believe we're now supposed to let kerberos/Samba/other black boxes
*ask* the KDC and DNS for information rather than telling information.
 Hence the recent IP changes for our ADS DCs didn't have to be added
anywhere.

Some troubleshooting work so far:

- kinit as myself (I'm the machine admin but not the ADS admin, whose
creds. we do not have)
- net ads testjoin (ok)
- wbinfo -a <my ads id> ok
- check networking and name resolution: seems ok
- turn off nscd
- wbinfo -K <my ads id> ok

Items I'm thinking about:
- is there a means to clear the sid/rid cache (see near end of logs below).
- I had to widen my idmap range from 10000-20000 to 10000-200000
- does set-auth-user matter these days?

Below are the logs from log.winbindd from wbinfo -i <ads id> using my ads id.

I appreciate any help with this odd behavior.

[2008/11/19 13:12:41,  4] winbindd/winbindd_dual.c:fork_domain_child(1207)
  child daemon request 21
[2008/11/19 13:12:41,  3]
winbindd/winbindd_async.c:winbindd_dual_lookupname(442)
  [20054]: lookupname ADS+<ads id>
[2008/11/19 13:12:41,  3] winbindd/winbindd_rpc.c:msrpc_name_to_sid(295)
  rpc: name_to_sid name=ADS\<ads id>
[2008/11/19 13:12:41,  3] winbindd/winbindd_rpc.c:msrpc_name_to_sid(299)
  name_to_sid [rpc] ADS\<ads id> for domain ADS
[2008/11/19 13:12:41,  4] winbindd/winbindd_dual.c:fork_domain_child(1207)
  child daemon request 55
[2008/11/19 13:12:41,  3] winbindd/winbindd_user.c:winbindd_dual_userinfo(139)
  [20054]: lookupsid S-1-5-21-1085031214...rest of correct sid for this ads id
[2008/11/19 13:12:41,  3] winbindd/winbindd_ads.c:query_user(426)
  ads: query_user
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_do_paged_search_args(779)
  ads_do_paged_search_args:
ldap_search_with_timeout((objectSid=\01\05\00...)) -> Can't contact
LDAP server
[2008/11/19 13:12:41,  3] libads/ldap_utils.c:ads_do_search_retry_internal(76)
  Reopening ads connection to realm 'ADS.IU.EDU' after error Can't
contact LDAP server
[2008/11/19 13:12:41,  3] libsmb/namequery.c:get_dc_list(1909)
  get_dc_list: preferred server list: "iu-mssg-adsdc06.ads.iu.edu, ads.iu.edu"
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_connect(430)
  Successfully contacted LDAP server 129.79.7.130
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_connect(480)
  Connected to LDAP server iu-mssg-adsdc06.ads.iu.edu
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(789)
  ads_sasl_spnego_bind: got server principal name =
not_defined_in_RFC4178 at please_ignore
[2008/11/19 13:12:41,  3] libsmb/clikrb5.c:ads_cleanup_expired_creds(604)
  ads_cleanup_expired_creds: Ticket in ccache[MEMORY:winbind_ccache]
expiration Wed, 19 Nov 2008 22:10:00 EST
[2008/11/19 13:12:41,  3] libsmb/clikrb5.c:ads_krb5_mk_req(713)
  ads_krb5_mk_req: server marked as OK to delegate to, building forwardable TGT
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_do_paged_search_args(779)
  ads_do_paged_search_args:
ldap_search_with_timeout((objectSid=\01\05\00...)) -> Can't contact
LDAP server
[2008/11/19 13:12:41,  3] libads/ldap_utils.c:ads_do_search_retry_internal(76)
  Reopening ads connection to realm 'ADS.IU.EDU' after error Can't
contact LDAP server
[2008/11/19 13:12:41,  3] libsmb/namequery.c:get_dc_list(1909)
  get_dc_list: preferred server list: "129.79.7.130, ads.iu.edu"
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_connect(430)
  Successfully contacted LDAP server 129.79.7.130
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_connect(480)
  Connected to LDAP server iu-mssg-adsdc06.ads.iu.edu
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(780)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2008/11/19 13:12:41,  3] libads/sasl.c:ads_sasl_spnego_bind(789)
  ads_sasl_spnego_bind: got server principal name =
not_defined_in_RFC4178 at please_ignore
[2008/11/19 13:12:41,  3] libsmb/clikrb5.c:ads_cleanup_expired_creds(604)
  ads_cleanup_expired_creds: Ticket in ccache[MEMORY:winbind_ccache]
expiration Wed, 19 Nov 2008 22:10:00 EST
[2008/11/19 13:12:41,  3] libsmb/clikrb5.c:ads_krb5_mk_req(713)
  ads_krb5_mk_req: server marked as OK to delegate to, building forwardable TGT
[2008/11/19 13:12:41,  3] libads/ldap.c:ads_do_paged_search_args(779)
  ads_do_paged_search_args:
ldap_search_with_timeout((objectSid=\01\05\00...)) -> Can't contact
LDAP server
[2008/11/19 13:12:41,  1] libads/ldap_utils.c:ads_do_search_retry_internal(111)
  ads reopen failed after error Can't contact LDAP server
[2008/11/19 13:12:41,  1] winbindd/winbindd_ads.c:query_user(493)
  query_user(sid=S-1-5-21-1085031214...rest of correct sid for this
ads id) ads_search: Can't contact LDAP server
[2008/11/19 13:12:41,  1] winbindd/winbindd_user.c:winbindd_dual_userinfo(150)
  error getting user info for sid S-1-5-21-1085031214...rest of
correct sid for this ads id
[2008/11/19 13:12:47,  4] winbindd/winbindd_dual.c:fork_domain_child(1207)
  child daemon request 21
[2008/11/19 13:12:47,  3]
winbindd/winbindd_async.c:winbindd_dual_lookupname(442)
  [20054]: lookupname ADS+wwwrun
[2008/11/19 13:12:47,  4] winbindd/winbindd_dual.c:fork_domain_child(1207)
  child daemon request 21
[2008/11/19 13:12:47,  3]
winbindd/winbindd_async.c:winbindd_dual_lookupname(442)
  [20054]: lookupname ADS+wwwrun
[2008/11/19 13:12:48,  4] winbindd/winbindd_dual.c:fork_domain_child(1207)
  child daemon request 21