RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1351290 - Winbind idmap ad plugin unable to retrieve POSIX attributes between AD forests with one-way trust
Summary: Winbind idmap ad plugin unable to retrieve POSIX attributes between AD forest...
Keywords:
Status: CLOSED CANTFIX
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: samba
Version: 6.8
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: rc
: ---
Assignee: Andreas Schneider
QA Contact: qe-baseos-daemons
URL:
Whiteboard:
Depends On:
Blocks: 1392562
TreeView+ depends on / blocked
 
Reported: 2016-06-29 15:42 UTC by Giuseppe Ragusa
Modified: 2022-03-13 14:04 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1392562 (view as bug list)
Environment:
Last Closed: 2016-11-04 12:58:38 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Giuseppe Ragusa 2016-06-29 15:42:49 UTC
Description of problem:

According to latest Red Hat docs for RHEL/AD interoperability, using Winbind should be the preferred method in presence of multiple AD forests.
Unfortunately, the ad idmapping plugin is unable to retrieve RFC2307bis POSIX attributes in our case: the kerberized (through SPNEGO/GSSAPI) bind to the logging-in user's forest DC LDAP service fails (and the user logon fails too) if there is no outgoing trust (using Microsoft terminology and conventions here) from the logging-in user's forest to the one in which the Samba machine is joined.


Version-Release number of selected component (if applicable):

Up to latest samba-winbind-3.6.23-35.el6_8 - tested with Windows 2012R2 forests


How reproducible:

Always, just follow the steps below.

Steps to Reproduce:

1) Create three single-domain AD forests (tslab.eni.intranet, tslabremote.eni.intranet and tslabusers.eni.intranet)

2) Create a forest wide one-way trust from both tslab.eni.intranet and tslabremote.eni.intranet to tslabusers.eni.intranet (using Microsoft terminology and conventions here) and a forest wide two-way trust between tslab.eni.intranet and tslabremote.eni.intranet

3) Configure and join Samba machine t4lab15103.tslabremote.eni.intranet to tslabremote.eni.intranet

/etc/samba/smb.conf:

[global]
        realm = TSLABREMOTE.ENI.INTRANET
        workgroup = TSLABREMOTE
        server string = Samba Server Version %v
        security = ads
        kerberos method = secrets and keytab
        client signing = yes
        client use spnego = yes
        name resolve order = host
        idmap config TSLABUSERS : backend = ad
        idmap config TSLABUSERS : range = 2000000-2999999
        idmap config TSLABUSERS : schema_mode = rfc2307
        idmap config TSLABREMOTE : backend = ad
        idmap config TSLABREMOTE : range = 1000000-1999999
        idmap config TSLABREMOTE : schema_mode = rfc2307
        idmap config TSLAB : backend = ad
        idmap config TSLAB : range = 3000000-3999999
        idmap config TSLAB : schema_mode = rfc2307
        idmap config * : backend = autorid
        idmap config * : range = 4020000-204019999
        idmap config * : rangesize = 2000000
        winbind nss info = rfc2307
        winbind enum users = no
        winbind enum groups = no
        winbind use default domain = no
        winbind nested groups = yes
        winbind expand groups = 2
        winbind refresh tickets = yes
        winbind offline logon = yes
        winbind trusted domains only = no
        winbind normalize names = no
        allow trusted domains = yes
        template homedir = /home/%D/%U
        template shell = /bin/bash
        log level = 10 winbind:10
        log file = /var/log/samba/log.%m
        max log size = 50
        load printers = no

/etc/krb5.conf:

[logging]
 default = FILE:/var/log/krb5libs.log
 kdc = FILE:/var/log/krb5kdc.log
 admin_server = FILE:/var/log/kadmind.log
[libdefaults]
 default_realm = TSLABREMOTE.ENI.INTRANET
 dns_lookup_realm = true
 dns_lookup_kdc = true
 ticket_lifetime = 24h
 renew_lifetime = 7d
 forwardable = true
 proxiable = false
[realms]
[domain_realm]
 .tslabusers.eni.intranet = TSLABUSERS.ENI.INTRANET
 tslabusers.eni.intranet = TSLABUSERS.ENI.INTRANET
 .tslab.eni.intranet = TSLAB.ENI.INTRANET
 tslab.eni.intranet = TSLAB.ENI.INTRANET
[appdefaults]
pam = {
   ticket_lifetime = 1d
   renew_lifetime = 1d
   forwardable = true
   proxiable = false
   minimum_uid = 1
}

kinit Administrator.INTRANET

klist

net ads join -k

authconfig --kickstart --update --enablelocauthorize --enablewinbind --enablewinbindauth

sed -i -e 's/^;cached_login =.*\$/cached_login = yes/' -e 's/^;krb5_auth =.*\$/krb5_auth = yes/' -e 's/^;krb5_ccache_type =.*\$/krb5_ccache_type = FILE/' /etc/security/pam_winbind.conf

service winbind restart
service oddjobd restart

chkconfig winbind on
chkconfig oddjobd on

kdestroy

4) Create a test user in forest tslabusers.eni.intranet and a second test user in forest tslab.eni.intranet

5) Fill all uidNumber/gidNumber fields for all test users (and their primary groups, by default "Domain Users") using "ADSI Edit"

6) Try logging in on Samba machine using test users' accounts

Actual results:

Login succeeds for tslab.eni.intranet user.

Login fails for tslabusers.eni.intranet user with (excerpt from log.winbindd-idmap):

[2016/06/24 15:28:18.227378, 10] libads/sitename_cache.c:70(sitename_store)
  sitename_store: realm = [TSLABUSERS], sitename = [Remote-Site], expire = [2085923199]
[2016/06/24 15:28:18.227406, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = AD_SITENAME/DOMAIN/TSLABUSERS and timeout = (null) (619148301 seconds ahead)
[2016/06/24 15:28:18.227454, 10] libads/sitename_cache.c:70(sitename_store)
  sitename_store: realm = [tslabusers.eni.intranet], sitename = [Remote-Site], expire = [2085923199]
[2016/06/24 15:28:18.227480, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = AD_SITENAME/DOMAIN/TSLABUSERS.ENI.INTRANET and timeout = (null) (619148301 seconds ahead)
[2016/06/24 15:28:18.227526,  3] libads/ldap.c:629(ads_connect)
  Successfully contacted LDAP server 192.168.100.4
[2016/06/24 15:28:18.227551, 10] libads/ldap.c:68(ldap_open_with_timeout)
  Opening connection to LDAP server 'T4LAB15104.tslabusers.eni.intranet:389', timeout 15 seconds
[2016/06/24 15:28:18.228519, 10] libads/ldap.c:82(ldap_open_with_timeout)
  Connected to LDAP server 'T4LAB15104.tslabusers.eni.intranet:389'
[2016/06/24 15:28:18.228556,  3] libads/ldap.c:683(ads_connect)
  Connected to LDAP server T4LAB15104.tslabusers.eni.intranet
[2016/06/24 15:28:18.228580, 10] libads/ldap.c:171(ads_closest_dc)
  ads_closest_dc: NBT_SERVER_CLOSEST flag set
[2016/06/24 15:28:18.228608, 10] libsmb/namequery.c:89(saf_store)
  saf_store: domain = [TSLABUSERS], server = [T4LAB15104.tslabusers.eni.intranet], expire = [1466775798]
[2016/06/24 15:28:18.228633, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = SAF/DOMAIN/TSLABUSERS and timeout = Fri Jun 24 15:43:18 2016
   (900 seconds ahead)
[2016/06/24 15:28:18.228689, 10] libsmb/namequery.c:89(saf_store)
  saf_store: domain = [tslabusers.eni.intranet], server = [T4LAB15104.tslabusers.eni.intranet], expire = [1466775798]
[2016/06/24 15:28:18.228716, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = SAF/DOMAIN/TSLABUSERS.ENI.INTRANET and timeout = Fri Jun 24 15:43:18 2016
   (900 seconds ahead)
[2016/06/24 15:28:18.229095,  4] libads/ldap.c:2844(ads_current_time)
  time offset is 0 seconds
[2016/06/24 15:28:18.229325,  4] libads/sasl.c:1242(ads_sasl_bind)
  Found SASL mechanism GSS-SPNEGO
[2016/06/24 15:28:18.229711,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.30
[2016/06/24 15:28:18.229741,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2
[2016/06/24 15:28:18.229764,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2
[2016/06/24 15:28:18.229786,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2.3
[2016/06/24 15:28:18.229809,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10
[2016/06/24 15:28:18.229831,  3] libads/sasl.c:909(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got server principal name = not_defined_in_RFC4178@please_ignore
[2016/06/24 15:28:18.232756, 10] libads/sasl.c:930(ads_sasl_spnego_bind)
  ads_sasl_spnego_krb5_bind failed with: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database, calling kinit
[2016/06/24 15:28:18.232908, 10] libads/kerberos.c:191(kerberos_kinit_password_ext)
  kerberos_kinit_password: as T4LAB15103$@TSLABREMOTE.ENI.INTRANET using [MEMORY:winbind_ccache] as ccache and config [/var/lib/samba/smb_krb5/krb5.conf.TSLABREMOTE]
[2016/06/24 15:28:18.250073,  0] libads/sasl.c:939(ads_sasl_spnego_bind)
  kinit succeeded but ads_sasl_spnego_krb5_bind failed: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database
[2016/06/24 15:28:18.250249,  1] winbindd/idmap_ad.c:149(ad_idmap_cached_connection_internal)
  ad_idmap_cached_connection_internal: failed to connect to AD
[2016/06/24 15:28:18.250316,  1] winbindd/idmap_ad.c:549(idmap_ad_sids_to_unixids)
  ADS uninitialized: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database
[2016/06/24 15:28:18.250355, 10] winbindd/idmap_util.c:187(idmap_sid_to_uid)
  idmap_backends_sid_to_unixid failed: NT_STATUS_UNSUCCESSFUL
[2016/06/24 15:28:18.250404, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = IDMAP/SID2UID/S-1-5-21-3050777515-1862613487-2122822448-1112 and timeout = Fri Jun 24 15:30:18 2016
   (120 seconds ahead)
[2016/06/24 15:28:18.250463,  1] ../librpc/ndr/ndr.c:440(ndr_print_function_debug)
       wbint_Sid2Uid: struct wbint_Sid2Uid
          out: struct wbint_Sid2Uid
              uid                      : *
                  uid                      : 0x0000000000000000 (0)
              result                   : NT_STATUS_UNSUCCESSFUL
[2016/06/24 15:28:18.250556,  4] winbindd/winbindd_dual.c:1322(child_handler)
  Finished processing child request 59
[2016/06/24 15:28:18.250582, 10] winbindd/winbindd_dual.c:1338(child_handler)
  Writing 3508 bytes to parent

Expected results:

Login succeeds also for tslabusers.eni.intranet user.

Additional info:

According to Microsoft docs and best practices, the forest is the security boundary in Active Directory.
Many security-conscious organizations deploy multiple forests and a separate forest for users' accounts is a common scenario, with further multiple resource forests containing mainly machine accounts (and Linux machines too).

Since Windows machines behave correctly in such a scenario, Samba should work too (without requiring the creation of a whole parallel IdM/IPA forest).

The issue seems to be a fundamental one, since it is simply reproducible on the Samba machine with:

kinit -k 'T4LAB15103$@TSLABREMOTE.ENI.INTRANET'

ldapsearch -Y GSSAPI -H ldap://t4lab15104.tslabusers.eni.intranet -b "ou=TSPORTAL,dc=tslabusers,dc=eni,dc=intranet" sAMAccountName=testuser

We wonder whether winbind could use the logging-in user's Kerberos credentials to perform the LDAP bind and retrieve it's RFC2307bis attributes, instead of using the local machine's Kerberos credentials that obviously fail to get a ticket in absence of a proper trust.

Comment 3 Michael Adam 2016-08-09 15:00:30 UTC
If the trust is in the right direction, then this should work.

To understand, if only idmap_ad is affected, let's try
authentication:

on the samba server, please do:

wbinfo -a TLABUSER\\someuser

and check if that works. it will use the trust but not do ldap

Comment 5 Giuseppe Ragusa 2016-08-30 09:49:26 UTC
Unfortunately the AD trust is (using Microsoft terminology and conventions):

unidirectional outgoing from the resource forest (which the RHEL machine is joined to) to the users forest (which the users attempting login belong to)

an this is intentional for security reasons as detailed in comment #1

Since we need the solution working in a reasonable timeframe, we got a temporary exception for a first proof-of-concept and modified the setup mentioned in comment #1 as follows:

2) Create a forest wide one-way trust from both tslab.eni.intranet and tslabremote.eni.intranet to tslabusers.eni.intranet (using Microsoft terminology and conventions here) and a forest wide one-way trust from tslabusers.eni.intranet to tslab.eni.intranet

Now we temporarily work with RHEL machines joined to tslab.eni.intranet and all goes well.

But if I try to join a machine (named t4lab15124) to tslabremote.eni.intranet the problem is still reproducible and your test confirms that only idmap_ad is affected as reported in comment #1

[root@t4lab15124 ~]# wbinfo -a TSLABUSERS\\uid0746948
Enter TSLABUSERS\uid0746948's password:
plaintext password authentication succeeded
Enter TSLABUSERS\uid0746948's password:
challenge/response password authentication succeeded

While the following gets logged (/var/log/samba/log.winbindd-idmap) if trying to logon via SSH on t4lab15124 using the identity above (the logon obviously fails):

[2016/08/30 11:21:34.775923, 10] winbindd/winbindd_dual.c:70(child_read_request)
  Need to read 56 extra bytes
[2016/08/30 11:21:34.775980,  4] winbindd/winbindd_dual.c:1314(child_handler)
  child daemon request 59
[2016/08/30 11:21:34.776004, 10] winbindd/winbindd_dual.c:439(child_process_request)
  child_process_request: request fn NDRCMD
[2016/08/30 11:21:34.776024, 10] winbindd/winbindd_dual_ndr.c:315(winbindd_dual_ndrcmd)
  winbindd_dual_ndrcmd: Running command WBINT_SID2UID (no domain)
[2016/08/30 11:21:34.776050,  1] ../librpc/ndr/ndr.c:440(ndr_print_function_debug)
       wbint_Sid2Uid: struct wbint_Sid2Uid
          in: struct wbint_Sid2Uid
              dom_name                 : *
                  dom_name                 : 'TSLABUSERS'
              sid                      : *
                  sid                      : S-1-5-21-3050777515-1862613487-2122822448-1112
[2016/08/30 11:21:34.776131, 10] winbindd/idmap_util.c:161(idmap_sid_to_uid)
  idmap_sid_to_uid: sid = [S-1-5-21-3050777515-1862613487-2122822448-1112], domain = 'TSLABUSERS'
[2016/08/30 11:21:34.776168, 10] winbindd/idmap.c:507(idmap_backends_sid_to_unixid)
  idmap_backends_sid_to_unixid: domain = 'TSLABUSERS', sid = [S-1-5-21-3050777515-1862613487-2122822448-1112]
[2016/08/30 11:21:34.776192, 10] winbindd/idmap.c:376(idmap_find_domain)
  idmap_find_domain called for domain 'TSLABUSERS'
[2016/08/30 11:21:34.776246, 10] winbindd/idmap_ad.c:77(ad_idmap_cached_connection_internal)
  ad_idmap_cached_connection: called for domain 'TSLABUSERS'
[2016/08/30 11:21:34.776281,  5] libsmb/namequery.c:194(saf_fetch)
  saf_fetch: Returning "T4LAB15104.tslabusers.eni.intranet" for "TSLABUSERS" domain
[2016/08/30 11:21:34.776303, 10] winbindd/idmap_ad.c:117(ad_idmap_cached_connection_internal)
  ldap_server from saf cache: 'T4LAB15104.tslabusers.eni.intranet'
[2016/08/30 11:21:34.776324, 10] winbindd/idmap_ad.c:126(ad_idmap_cached_connection_internal)
  find_domain_from_name_noinit found realm 'tslabusers.eni.intranet' for  domain 'TSLABUSERS'
[2016/08/30 11:21:34.776359,  5] libads/sitename_cache.c:105(sitename_fetch)
  sitename_fetch: Returning sitename for tslabusers.eni.intranet: "Remote-Site"
[2016/08/30 11:21:34.776385,  4] libsmb/namequery_dc.c:76(ads_dc_name)
  ads_dc_name: domain=TSLABUSERS
[2016/08/30 11:21:34.776417,  5] libads/sitename_cache.c:105(sitename_fetch)
  sitename_fetch: Returning sitename for tslabusers.eni.intranet: "Remote-Site"
[2016/08/30 11:21:34.776440,  6] libads/ldap.c:363(ads_find_dc)
  ads_find_dc: (cldap) looking for realm 'tslabusers.eni.intranet'
[2016/08/30 11:21:34.776460,  8] libsmb/namequery.c:2721(get_sorted_dc_list)
  get_sorted_dc_list: attempting lookup for name tslabusers.eni.intranet (sitename Remote-Site) using [ads]
[2016/08/30 11:21:34.776492,  5] libsmb/namequery.c:194(saf_fetch)
  saf_fetch: Returning "T4LAB15104.tslabusers.eni.intranet" for "tslabusers.eni.intranet" domain
[2016/08/30 11:21:34.776517,  3] libsmb/namequery.c:2533(get_dc_list)
  get_dc_list: preferred server list: "T4LAB15104.tslabusers.eni.intranet, *"
[2016/08/30 11:21:34.776538, 10] libsmb/namequery.c:2042(internal_resolve_name)
  internal_resolve_name: looking up tslabusers.eni.intranet#1c (sitename Remote-Site)
[2016/08/30 11:21:34.776563,  5] libsmb/namecache.c:165(namecache_fetch)
  name tslabusers.eni.intranet#1C found.
[2016/08/30 11:21:34.776604, 10] libsmb/namequery.c:1079(remove_duplicate_addrs2)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2016/08/30 11:21:34.776629,  8] libsmb/namequery.c:2554(get_dc_list)
  Adding 1 DC's from auto lookup
[2016/08/30 11:21:34.776657,  5] libads/sitename_cache.c:105(sitename_fetch)
  sitename_fetch: Returning sitename for TSLABREMOTE.ENI.INTRANET: "Remote-Site"
[2016/08/30 11:21:34.776680, 10] libsmb/namequery.c:2042(internal_resolve_name)
  internal_resolve_name: looking up T4LAB15104.tslabusers.eni.intranet#20 (sitename Remote-Site)
[2016/08/30 11:21:34.776706,  5] libsmb/namecache.c:165(namecache_fetch)
  name T4LAB15104.tslabusers.eni.intranet#20 found.
[2016/08/30 11:21:34.776740, 10] libsmb/namequery.c:1079(remove_duplicate_addrs2)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2016/08/30 11:21:34.776772,  9] libsmb/conncache.c:150(check_negative_conn_cache)
  check_negative_conn_cache returning result 0 for domain tslabusers.eni.intranet server 192.168.100.4
[2016/08/30 11:21:34.776801,  9] libsmb/conncache.c:150(check_negative_conn_cache)
  check_negative_conn_cache returning result 0 for domain tslabusers.eni.intranet server 192.168.100.4
[2016/08/30 11:21:34.776823, 10] libsmb/namequery.c:1079(remove_duplicate_addrs2)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2016/08/30 11:21:34.776844,  4] libsmb/namequery.c:2670(get_dc_list)
  get_dc_list: returning 1 ip addresses in an ordered list
[2016/08/30 11:21:34.776873,  4] libsmb/namequery.c:2671(get_dc_list)
  get_dc_list: 192.168.100.4:389
[2016/08/30 11:21:34.776902,  9] libsmb/conncache.c:150(check_negative_conn_cache)
  check_negative_conn_cache returning result 0 for domain tslabusers.eni.intranet server 192.168.100.4
[2016/08/30 11:21:34.776926,  5] libads/ldap.c:213(ads_try_connect)
  ads_try_connect: sending CLDAP request to 192.168.100.4 (realm: tslabusers.eni.intranet)
[2016/08/30 11:21:34.777200,  1] ../librpc/ndr/ndr.c:403(ndr_print_debug)
       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX
          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)
          sbz                      : 0x0000 (0)
          server_type              : 0x0000f1fc (61948)
                 0: NBT_SERVER_PDC
                 1: NBT_SERVER_GC
                 1: NBT_SERVER_LDAP
                 1: NBT_SERVER_DS
                 1: NBT_SERVER_KDC
                 1: NBT_SERVER_TIMESERV
                 1: NBT_SERVER_CLOSEST
                 1: NBT_SERVER_WRITABLE
                 0: NBT_SERVER_GOOD_TIMESERV
                 0: NBT_SERVER_NDNC
                 0: NBT_SERVER_SELECT_SECRET_DOMAIN_6
                 1: NBT_SERVER_FULL_SECRET_DOMAIN_6
                 1: NBT_SERVER_ADS_WEB_SERVICE
                 0: NBT_SERVER_HAS_DNS_NAME
                 0: NBT_SERVER_IS_DEFAULT_NC
                 0: NBT_SERVER_FOREST_ROOT
          domain_uuid              : 959bb114-65ae-4570-b775-c46d361fe3a1
          forest                   : 'tslabusers.eni.intranet'
          dns_domain               : 'tslabusers.eni.intranet'
          pdc_dns_name             : 'T4LAB15104.tslabusers.eni.intranet'
          domain_name              : 'TSLABUSERS'
          pdc_name                 : 'T4LAB15104'
          user_name                : ''
          server_site              : 'Remote-Site'
          client_site              : 'Remote-Site'
          sockaddr_size            : 0x00 (0)
          sockaddr: struct nbt_sockaddr
              sockaddr_family          : 0x00000000 (0)
              pdc_ip                   : (null)
              remaining                : DATA_BLOB length=0
          next_closest_site        : NULL
          nt_version               : 0x00000005 (5)
                 1: NETLOGON_NT_VERSION_1
                 0: NETLOGON_NT_VERSION_5
                 1: NETLOGON_NT_VERSION_5EX
                 0: NETLOGON_NT_VERSION_5EX_WITH_IP
                 0: NETLOGON_NT_VERSION_WITH_CLOSEST_SITE
                 0: NETLOGON_NT_VERSION_AVOID_NT4EMUL
                 0: NETLOGON_NT_VERSION_PDC
                 0: NETLOGON_NT_VERSION_IP
                 0: NETLOGON_NT_VERSION_LOCAL
                 0: NETLOGON_NT_VERSION_GC
          lmnt_token               : 0xffff (65535)
          lm20_token               : 0xffff (65535)
[2016/08/30 11:21:34.777660, 10] libads/sitename_cache.c:70(sitename_store)
  sitename_store: realm = [TSLABUSERS], sitename = [Remote-Site], expire = [2085923199]
[2016/08/30 11:21:34.777686, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = AD_SITENAME/DOMAIN/TSLABUSERS and timeout = (null) (613374305 seconds ahead)
[2016/08/30 11:21:34.777725, 10] libads/sitename_cache.c:70(sitename_store)
  sitename_store: realm = [tslabusers.eni.intranet], sitename = [Remote-Site], expire = [2085923199]
[2016/08/30 11:21:34.777749, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = AD_SITENAME/DOMAIN/TSLABUSERS.ENI.INTRANET and timeout = (null) (613374305 seconds ahead)
[2016/08/30 11:21:34.777785,  3] libads/ldap.c:629(ads_connect)
  Successfully contacted LDAP server 192.168.100.4
[2016/08/30 11:21:34.777813,  5] libads/sitename_cache.c:105(sitename_fetch)
  sitename_fetch: Returning sitename for tslabusers.eni.intranet: "Remote-Site"
[2016/08/30 11:21:34.777837,  4] libsmb/namequery_dc.c:146(ads_dc_name)
  ads_dc_name: using server='T4LAB15104.TSLABUSERS.ENI.INTRANET' IP=192.168.100.4
[2016/08/30 11:21:34.777871,  5] libads/sitename_cache.c:105(sitename_fetch)
  sitename_fetch: Returning sitename for TSLABREMOTE.ENI.INTRANET: "Remote-Site"
[2016/08/30 11:21:34.777895, 10] libsmb/namequery.c:2042(internal_resolve_name)
  internal_resolve_name: looking up T4LAB15104.tslabusers.eni.intranet#20 (sitename Remote-Site)
[2016/08/30 11:21:34.777920,  5] libsmb/namecache.c:165(namecache_fetch)
  name T4LAB15104.tslabusers.eni.intranet#20 found.
[2016/08/30 11:21:34.777966, 10] libsmb/namequery.c:1079(remove_duplicate_addrs2)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2016/08/30 11:21:34.777994,  5] libads/ldap.c:213(ads_try_connect)
  ads_try_connect: sending CLDAP request to 192.168.100.4 (realm: tslabusers.eni.intranet)
[2016/08/30 11:21:34.778224,  1] ../librpc/ndr/ndr.c:403(ndr_print_debug)
       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX
          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)
          sbz                      : 0x0000 (0)
          server_type              : 0x0000f1fc (61948)
                 0: NBT_SERVER_PDC
                 1: NBT_SERVER_GC
                 1: NBT_SERVER_LDAP
                 1: NBT_SERVER_DS
                 1: NBT_SERVER_KDC
                 1: NBT_SERVER_TIMESERV
                 1: NBT_SERVER_CLOSEST
                 1: NBT_SERVER_WRITABLE
                 0: NBT_SERVER_GOOD_TIMESERV
                 0: NBT_SERVER_NDNC
                 0: NBT_SERVER_SELECT_SECRET_DOMAIN_6
                 1: NBT_SERVER_FULL_SECRET_DOMAIN_6
                 1: NBT_SERVER_ADS_WEB_SERVICE
                 0: NBT_SERVER_HAS_DNS_NAME
                 0: NBT_SERVER_IS_DEFAULT_NC
                 0: NBT_SERVER_FOREST_ROOT
          domain_uuid              : 959bb114-65ae-4570-b775-c46d361fe3a1
          forest                   : 'tslabusers.eni.intranet'
          dns_domain               : 'tslabusers.eni.intranet'
          pdc_dns_name             : 'T4LAB15104.tslabusers.eni.intranet'
          domain_name              : 'TSLABUSERS'
          pdc_name                 : 'T4LAB15104'
          user_name                : ''
          server_site              : 'Remote-Site'
          client_site              : 'Remote-Site'
          sockaddr_size            : 0x00 (0)
          sockaddr: struct nbt_sockaddr
              sockaddr_family          : 0x00000000 (0)
              pdc_ip                   : (null)
              remaining                : DATA_BLOB length=0
          next_closest_site        : NULL
          nt_version               : 0x00000005 (5)
                 1: NETLOGON_NT_VERSION_1
                 0: NETLOGON_NT_VERSION_5
                 1: NETLOGON_NT_VERSION_5EX
                 0: NETLOGON_NT_VERSION_5EX_WITH_IP
                 0: NETLOGON_NT_VERSION_WITH_CLOSEST_SITE
                 0: NETLOGON_NT_VERSION_AVOID_NT4EMUL
                 0: NETLOGON_NT_VERSION_PDC
                 0: NETLOGON_NT_VERSION_IP
                 0: NETLOGON_NT_VERSION_LOCAL
                 0: NETLOGON_NT_VERSION_GC
          lmnt_token               : 0xffff (65535)
          lm20_token               : 0xffff (65535)
[2016/08/30 11:21:34.778679, 10] libads/sitename_cache.c:70(sitename_store)
  sitename_store: realm = [TSLABUSERS], sitename = [Remote-Site], expire = [2085923199]
[2016/08/30 11:21:34.778705, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = AD_SITENAME/DOMAIN/TSLABUSERS and timeout = (null) (613374305 seconds ahead)
[2016/08/30 11:21:34.778742, 10] libads/sitename_cache.c:70(sitename_store)
  sitename_store: realm = [tslabusers.eni.intranet], sitename = [Remote-Site], expire = [2085923199]
[2016/08/30 11:21:34.778766, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = AD_SITENAME/DOMAIN/TSLABUSERS.ENI.INTRANET and timeout = (null) (613374305 seconds ahead)
[2016/08/30 11:21:34.778809,  3] libads/ldap.c:629(ads_connect)
  Successfully contacted LDAP server 192.168.100.4
[2016/08/30 11:21:34.778835, 10] libads/ldap.c:68(ldap_open_with_timeout)
  Opening connection to LDAP server 'T4LAB15104.tslabusers.eni.intranet:389', timeout 15 seconds
[2016/08/30 11:21:34.779207, 10] libads/ldap.c:82(ldap_open_with_timeout)
  Connected to LDAP server 'T4LAB15104.tslabusers.eni.intranet:389'
[2016/08/30 11:21:34.779251,  3] libads/ldap.c:683(ads_connect)
  Connected to LDAP server T4LAB15104.tslabusers.eni.intranet
[2016/08/30 11:21:34.779273, 10] libads/ldap.c:171(ads_closest_dc)
  ads_closest_dc: NBT_SERVER_CLOSEST flag set
[2016/08/30 11:21:34.779296, 10] libsmb/namequery.c:89(saf_store)
  saf_store: domain = [TSLABUSERS], server = [T4LAB15104.tslabusers.eni.intranet], expire = [1472549794]
[2016/08/30 11:21:34.779321, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = SAF/DOMAIN/TSLABUSERS and timeout = Tue Aug 30 11:36:34 2016
   (900 seconds ahead)
[2016/08/30 11:21:34.779363, 10] libsmb/namequery.c:89(saf_store)
  saf_store: domain = [tslabusers.eni.intranet], server = [T4LAB15104.tslabusers.eni.intranet], expire = [1472549794]
[2016/08/30 11:21:34.779388, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = SAF/DOMAIN/TSLABUSERS.ENI.INTRANET and timeout = Tue Aug 30 11:36:34 2016
   (900 seconds ahead)
[2016/08/30 11:21:34.779551,  4] libads/ldap.c:2844(ads_current_time)
  time offset is 0 seconds
[2016/08/30 11:21:34.779681,  4] libads/sasl.c:1242(ads_sasl_bind)
  Found SASL mechanism GSS-SPNEGO
[2016/08/30 11:21:34.779904,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.30
[2016/08/30 11:21:34.779934,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2
[2016/08/30 11:21:34.779954,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2
[2016/08/30 11:21:34.779975,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2.3
[2016/08/30 11:21:34.779995,  3] libads/sasl.c:900(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10
[2016/08/30 11:21:34.780015,  3] libads/sasl.c:909(ads_sasl_spnego_bind)
  ads_sasl_spnego_bind: got server principal name = not_defined_in_RFC4178@please_ignore
[2016/08/30 11:21:34.781276, 10] libads/sasl.c:930(ads_sasl_spnego_bind)
  ads_sasl_spnego_krb5_bind failed with: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database, calling kinit
[2016/08/30 11:21:34.781343, 10] libads/kerberos.c:191(kerberos_kinit_password_ext)
  kerberos_kinit_password: as T4LAB15124$@TSLABREMOTE.ENI.INTRANET using [MEMORY:winbind_ccache] as ccache and config [/var/lib/samba/smb_krb5/krb5.conf.TSLABREMOTE]
[2016/08/30 11:21:34.795083,  0] libads/sasl.c:939(ads_sasl_spnego_bind)
  kinit succeeded but ads_sasl_spnego_krb5_bind failed: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database
[2016/08/30 11:21:34.795193,  1] winbindd/idmap_ad.c:149(ad_idmap_cached_connection_internal)
  ad_idmap_cached_connection_internal: failed to connect to AD
[2016/08/30 11:21:34.795257,  1] winbindd/idmap_ad.c:549(idmap_ad_sids_to_unixids)
  ADS uninitialized: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database
[2016/08/30 11:21:34.795300, 10] winbindd/idmap_util.c:187(idmap_sid_to_uid)
  idmap_backends_sid_to_unixid failed: NT_STATUS_UNSUCCESSFUL
[2016/08/30 11:21:34.795328, 10] lib/gencache.c:183(gencache_set_data_blob)
  Adding cache entry with key = IDMAP/SID2UID/S-1-5-21-3050777515-1862613487-2122822448-1112 and timeout = Tue Aug 30 11:23:34 2016
   (120 seconds ahead)
[2016/08/30 11:21:34.795377,  1] ../librpc/ndr/ndr.c:440(ndr_print_function_debug)
       wbint_Sid2Uid: struct wbint_Sid2Uid
          out: struct wbint_Sid2Uid
              uid                      : *
                  uid                      : 0x0000000000000000 (0)
              result                   : NT_STATUS_UNSUCCESSFUL
[2016/08/30 11:21:34.795451,  4] winbindd/winbindd_dual.c:1322(child_handler)
  Finished processing child request 59
[2016/08/30 11:21:34.795473, 10] winbindd/winbindd_dual.c:1338(child_handler)
  Writing 3508 bytes to parent

Comment 7 Andreas Schneider 2016-10-18 14:18:27 UTC
Could you stop winbindd and start it manually using:

KRB5_TRACE=/dev/stderr winbindd

Comment 8 Andreas Schneider 2016-10-18 14:19:15 UTC
This will give more details in the winbind log what is going on with Kerberos here.

Comment 9 Giuseppe Ragusa 2016-11-02 16:08:20 UTC
Here is what ends up in the logs (I am using a new client since the old one was reconfigured for other tests; the client hostname now is t4lab15126.tslabremote.eni.intranet and the forest setup is the same as in my comment #5 above).

Relevant lines in log.wb-TSLABUSERS:

[18529] 1478101680.234499: AS key obtained for encrypted timestamp: aes256-cts/9A6B
[18529] 1478101680.234536: Encrypted timestamp (for 1478101680.234506): plain 301AA011180F32303136313130323135343830305AA105020303940A, encrypted 62B2262E016EB959D0B157
4C49C372E3BE1056472F95105A1283CD04A208E43C731210FD17DC88FAE7B75AE1EF0017D2114C51332081A3C6
[18529] 1478101680.234548: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
[18529] 1478101680.234553: Produced preauth for next request: 2
[18529] 1478101680.234565: Sending request (290 bytes) to TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.234611: Sending initial UDP request to dgram 192.168.100.5:88
[18529] 1478101680.235237: Received answer from dgram 192.168.100.5:88
[18529] 1478101680.235266: Response was from master KDC
[18529] 1478101680.235280: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP
[18529] 1478101680.235286: Request or response is too big for UDP; retrying with TCP
[18529] 1478101680.235291: Sending request (290 bytes) to TSLABREMOTE.ENI.INTRANET (tcp only)
[18529] 1478101680.235316: Initiating TCP connection to stream 192.168.100.5:88
[18529] 1478101680.235457: Sending TCP request to stream 192.168.100.5:88
[18529] 1478101680.236041: Received answer from stream 192.168.100.5:88
[18529] 1478101680.236108: Response was from master KDC
[18529] 1478101680.236138: Processing preauth types: 19
[18529] 1478101680.236147: Selected etype info: etype aes256-cts, salt "TSLABREMOTE.ENI.INTRANEThostt4lab15126.tslabremote.eni.intranet", params ""
[18529] 1478101680.236152: Produced preauth for next request: (empty)
[18529] 1478101680.236160: AS key determined by preauth: aes256-cts/9A6B
[18529] 1478101680.236192: Decrypted AS reply; session key is: aes256-cts/2567
[18529] 1478101680.236205: FAST negotiation: unavailable
[18529] 1478101680.236233: Initializing MEMORY:cliconnect with default princ T4LAB15126$@TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.236244: Removing T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET from MEMORY:cliconnect
[18529] 1478101680.236250: Storing T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET in MEMORY:cliconnect
[18529] 1478101680.236382: Getting credentials T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> cifs/T4LAB15104.tslabusers.eni.intranet.INTRANET using ccache MEMORY:cliconnect
[18529] 1478101680.236405: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> cifs/T4LAB15104.tslabusers.eni.intranet.INTRANET from MEMORY:cliconnect with result: -1765328243/Matching credential not found
[18529] 1478101680.236422: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET from MEMORY:cliconnect with result
: -1765328243/Matching credential not found
[18529] 1478101680.236436: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET from MEMORY:cliconnect with result: 0/Success
[18529] 1478101680.236444: Starting with TGT for client realm: T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET
[18529] 1478101680.236462: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET from MEMORY:cliconnect with result: -1765328243/Matching credential not found
[18529] 1478101680.236469: Requesting TGT krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET using TGT krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET
[18529] 1478101680.236484: Generated subkey for TGS request: aes256-cts/0DC0
[18529] 1478101680.236490: etypes requested in TGS request: aes256-cts, aes128-cts, rc4-hmac
[18529] 1478101680.236553: Sending request (1569 bytes) to TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.236767: Initiating TCP connection to stream 192.168.100.5:88
[18529] 1478101680.236898: Sending TCP request to stream 192.168.100.5:88
[18529] 1478101680.237182: Received answer from stream 192.168.100.5:88
[18529] 1478101680.237226: Response was from master KDC
[18529] 1478101680.237254: TGS request result: -1765328377/Server not found in Kerberos database
[18529] 1478101680.242929: ccselect can't find appropriate cache for server principal ldap/t4lab15104.tslabusers.eni.intranet.INTRANET
[18529] 1478101680.243155: Getting initial credentials for T4LAB15126$@TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.243214: Sending request (210 bytes) to TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.243451: Sending initial UDP request to dgram 192.168.100.5:88
[18529] 1478101680.243830: Received answer from dgram 192.168.100.5:88
[18529] 1478101680.243860: Response was from master KDC
[18529] 1478101680.243874: Received error from KDC: -1765328359/Additional pre-authentication required
[18529] 1478101680.243896: Processing preauth types: 16, 15, 19, 2
[18529] 1478101680.243904: Selected etype info: etype aes256-cts, salt "TSLABREMOTE.ENI.INTRANEThostt4lab15126.tslabremote.eni.intranet", params ""
[18529] 1478101680.254237: AS key obtained for encrypted timestamp: aes256-cts/9A6B
[18529] 1478101680.254274: Encrypted timestamp (for 1478101680.254244): plain 301AA011180F32303136313130323135343830305AA105020303E124, encrypted B39D6F5A5FF8D7DB5CA71BA52555B42635F697F1C7B04138CDD41F081E0375924114C30510145E873A036DE3E23535312326CD781FD392B6
[18529] 1478101680.254294: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
[18529] 1478101680.254300: Produced preauth for next request: 2
[18529] 1478101680.254313: Sending request (290 bytes) to TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.254355: Sending initial UDP request to dgram 192.168.100.5:88
[18529] 1478101680.254968: Received answer from dgram 192.168.100.5:88
[18529] 1478101680.254998: Response was from master KDC
[18529] 1478101680.255011: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP
[18529] 1478101680.255017: Request or response is too big for UDP; retrying with TCP
[18529] 1478101680.255022: Sending request (290 bytes) to TSLABREMOTE.ENI.INTRANET (tcp only)
[18529] 1478101680.255046: Initiating TCP connection to stream 192.168.100.5:88
[18529] 1478101680.255187: Sending TCP request to stream 192.168.100.5:88
[18529] 1478101680.255763: Received answer from stream 192.168.100.5:88
[18529] 1478101680.255805: Response was from master KDC
[18529] 1478101680.255838: Processing preauth types: 19
[18529] 1478101680.255856: Selected etype info: etype aes256-cts, salt "TSLABREMOTE.ENI.INTRANEThostt4lab15126.tslabremote.eni.intranet", params ""
[18529] 1478101680.255862: Produced preauth for next request: (empty)
[18529] 1478101680.255870: AS key determined by preauth: aes256-cts/9A6B
[18529] 1478101680.255902: Decrypted AS reply; session key is: aes256-cts/5E10
[18529] 1478101680.255916: FAST negotiation: unavailable
[18529] 1478101680.255942: Initializing MEMORY:winbind_ccache with default princ T4LAB15126$@TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.255953: Removing T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache
[18529] 1478101680.255959: Storing T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET in MEMORY:winbind_ccache
[18529] 1478101680.256210: ccselect can't find appropriate cache for server principal ldap/t4lab15104.tslabusers.eni.intranet.INTRANET
[18529] 1478101680.256241: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18529] 1478101680.256256: Getting credentials T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> ldap/t4lab15104.tslabusers.eni.intranet.INTRANET using ccache MEMORY:winbind_ccache
[18529] 1478101680.256274: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> ldap/t4lab15104.tslabusers.eni.intranet.INTRANET from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18529] 1478101680.256289: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18529] 1478101680.256304: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache with result: 0/Success
[18529] 1478101680.256310: Starting with TGT for client realm: T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET
[18529] 1478101680.256326: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18529] 1478101680.256333: Requesting TGT krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET using TGT krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET
[18529] 1478101680.256348: Generated subkey for TGS request: aes256-cts/31CC
[18529] 1478101680.256357: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
[18529] 1478101680.256421: Sending request (1573 bytes) to TSLABREMOTE.ENI.INTRANET
[18529] 1478101680.256647: Initiating TCP connection to stream 192.168.100.5:88
[18529] 1478101680.256774: Sending TCP request to stream 192.168.100.5:88
[18529] 1478101680.257094: Received answer from stream 192.168.100.5:88
[18529] 1478101680.257138: Response was from master KDC
[18529] 1478101680.257166: TGS request result: -1765328377/Server not found in Kerberos database
[2016/11/02 16:48:00.257359,  0] libads/sasl.c:939(ads_sasl_spnego_bind)
  kinit succeeded but ads_sasl_spnego_krb5_bind failed: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database


Relevant lines in log.winbindd-idmap:


[2016/11/02 11:15:34.350208,  0] libads/sasl.c:939(ads_sasl_spnego_bind)
  kinit succeeded but ads_sasl_spnego_krb5_bind failed: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database
[18530] 1478101680.261677: ccselect can't find appropriate cache for server principal ldap/t4lab15104.tslabusers.eni.intranet.INTRANET
[18530] 1478101680.261982: Getting initial credentials for T4LAB15126$@TSLABREMOTE.ENI.INTRANET
[18530] 1478101680.262114: Sending request (210 bytes) to TSLABREMOTE.ENI.INTRANET
[18530] 1478101680.262697: Resolving hostname t4lab15105.tslabremote.eni.intranet.
[18530] 1478101680.262900: Sending initial UDP request to dgram 192.168.100.5:88
[18530] 1478101680.263619: Received answer from dgram 192.168.100.5:88
[18530] 1478101680.263865: Response was not from master KDC
[18530] 1478101680.263886: Received error from KDC: -1765328359/Additional pre-authentication required
[18530] 1478101680.263918: Processing preauth types: 16, 15, 19, 2
[18530] 1478101680.263932: Selected etype info: etype aes256-cts, salt "TSLABREMOTE.ENI.INTRANEThostt4lab15126.tslabremote.eni.intranet", params ""
[18530] 1478101680.274299: AS key obtained for encrypted timestamp: aes256-cts/9A6B
[18530] 1478101680.274356: Encrypted timestamp (for 1478101680.274307): plain 301AA011180F32303136313130323135343830305AA1050203042F83, encrypted 553AF6C345CAC2FA995D36
7B0BCFC49D35EF2F32CC8CAAC2C3DA3E1A6712156428DF45BD6AA9BBF7BCB7683318DEFEEB64778FBA2C177CE0
[18530] 1478101680.274371: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
[18530] 1478101680.274376: Produced preauth for next request: 2
[18530] 1478101680.274390: Sending request (290 bytes) to TSLABREMOTE.ENI.INTRANET
[18530] 1478101680.274791: Resolving hostname t4lab15105.tslabremote.eni.intranet.
[18530] 1478101680.274981: Sending initial UDP request to dgram 192.168.100.5:88
[18530] 1478101680.275567: Received answer from dgram 192.168.100.5:88
[18530] 1478101680.275765: Response was not from master KDC
[18530] 1478101680.275782: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP
[18530] 1478101680.275788: Request or response is too big for UDP; retrying with TCP
[18530] 1478101680.275793: Sending request (290 bytes) to TSLABREMOTE.ENI.INTRANET (tcp only)
[18530] 1478101680.275968: Resolving hostname t4lab15105.tslabremote.eni.intranet.
[18530] 1478101680.276150: Initiating TCP connection to stream 192.168.100.5:88
[18530] 1478101680.276272: Sending TCP request to stream 192.168.100.5:88
[18530] 1478101680.276843: Received answer from stream 192.168.100.5:88
[18530] 1478101680.277073: Response was not from master KDC
[18530] 1478101680.277100: Processing preauth types: 19
[18530] 1478101680.277109: Selected etype info: etype aes256-cts, salt "TSLABREMOTE.ENI.INTRANEThostt4lab15126.tslabremote.eni.intranet", params ""
[18530] 1478101680.277115: Produced preauth for next request: (empty)
[18530] 1478101680.277122: AS key determined by preauth: aes256-cts/9A6B
[18530] 1478101680.277168: Decrypted AS reply; session key is: aes256-cts/165F
[18530] 1478101680.277186: FAST negotiation: unavailable
[18530] 1478101680.277219: Initializing MEMORY:winbind_ccache with default princ T4LAB15126$@TSLABREMOTE.ENI.INTRANET
[18530] 1478101680.277231: Removing T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache
[18530] 1478101680.277238: Storing T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET in MEMORY:winbind_ccache
[18530] 1478101680.277491: ccselect can't find appropriate cache for server principal ldap/t4lab15104.tslabusers.eni.intranet.INTRANET
[18530] 1478101680.277519: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18530] 1478101680.277537: Getting credentials T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> ldap/t4lab15104.tslabusers.eni.intranet.INTRANET using ccache MEMORY:winbind_ccache
[18530] 1478101680.277570: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> ldap/t4lab15104.tslabusers.eni.intranet.INTRANET from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18530] 1478101680.277586: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18530] 1478101680.277602: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache with result: 0/Success
[18530] 1478101680.277609: Starting with TGT for client realm: T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET
[18530] 1478101680.277628: Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET from MEMORY:winbind_ccache with result: -1765328243/Matching credential not found
[18530] 1478101680.277635: Requesting TGT krbtgt/TSLABUSERS.ENI.INTRANET.INTRANET using TGT krbtgt/TSLABREMOTE.ENI.INTRANET.INTRANET
[18530] 1478101680.277654: Generated subkey for TGS request: aes256-cts/2926
[18530] 1478101680.277663: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
[18530] 1478101680.277734: Sending request (1573 bytes) to TSLABREMOTE.ENI.INTRANET
[18530] 1478101680.278270: Resolving hostname t4lab15105.tslabremote.eni.intranet.
[18530] 1478101680.278459: Resolving hostname t4lab15105.tslabremote.eni.intranet.
[18530] 1478101680.278649: Initiating TCP connection to stream 192.168.100.5:88
[18530] 1478101680.278770: Sending TCP request to stream 192.168.100.5:88
[18530] 1478101680.279041: Received answer from stream 192.168.100.5:88
[18530] 1478101680.279304: Response was not from master KDC
[18530] 1478101680.279321: TGS request result: -1765328377/Server not found in Kerberos database
[2016/11/02 16:48:00.279501,  0] libads/sasl.c:939(ads_sasl_spnego_bind)
  kinit succeeded but ads_sasl_spnego_krb5_bind failed: Unspecified GSS failure.  Minor code may provide more information : Server not found in Kerberos database

Comment 10 Andreas Schneider 2016-11-04 12:58:38 UTC
As you can see by the following log line:

Retrieving T4LAB15126$@TSLABREMOTE.ENI.INTRANET -> ldap/t4lab15104.tslabusers.eni.intranet.INTRANET

According to your description TSLABUSERS is trusting TSLABREMOTE. But here the machine account from TSLABREMOTE tries to access the LDAP server in TSLABUSERS to access the POSIX attributes. As the trust direction is in the opposite direction it wont get a ticket and will not be able to access LDAP.

I don't see how this can be solved in RHEL6. You can create a feature request for newer versions and report an upstream bug. But I'm not sure if we find an easy way to support this scenario.

Comment 11 Giuseppe Ragusa 2016-11-04 14:35:19 UTC
According to my description (see comment # 5 but it was clearly staed already in comment # 1 aka the bug description) the trust is uni-directional outgoing from TSLABREMOTE (resources forest) to TSLABUSERS (users forest).
Since it's AD, I'm using Microsoft terminology: this means that TSLABREMOTE trusts TSLABUSERS but the reverse is not true.

As I already stated in the bug additional info (see comment # 1 ), I perfectly understand that the issue is a fundamental one and the simple ldapsearch test I cited could demonstrate it immediately without any need for further Kerberos tracing etc.

You could argue (as Michael Adam did in comment # 3 ) that the trust is not "in the right direction", but there is undeniably a Red Hat documentation bug, because the Red Hat recommended configuration solution for interoperability in multi-forest AD environments has no chance to work in a very common (even a Microsoft security best practice) scenario.
This should be clearly stated: bi-directional forest trusts are currently mandatory for the Winbind based AD integration solution to work as advertised.

As I already stated in the bug description (aka comment # 1 ):

"...winbind could use the logging-in user's Kerberos credentials to perform the LDAP bind and retrieve it's RFC2307bis attributes, instead of using the local machine's Kerberos credentials that obviously fail to get a ticket in absence of a proper trust"

but I'm not a developer and at this level it is exactly what you said: a feature request for Winbind that maybe Red Hat could help develop and then incorporate in RHEL (maybe 7.x, maybe even 6.x by means of eventual samba4 package rebasing).


Note You need to log in before you can comment on or make changes to this bug.