Bug 12369 - kinit succeeded but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error occurred
Summary: kinit succeeded but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal err...
Status: RESOLVED FIXED
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: Winbind (show other bugs)
Version: 4.4.6
Hardware: All All
: P5 regression (vote)
Target Milestone: ---
Assignee: Karolin Seeger
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks: 12480
  Show dependency treegraph
 
Reported: 2016-10-08 12:57 UTC by Klaus Braun
Modified: 2016-12-22 06:49 UTC (History)
6 users (show)

See Also:


Attachments
gss_init_sec_context failed with [ The context has expired: Success] (7.68 KB, text/x-log)
2016-10-08 12:57 UTC, Klaus Braun
no flags Details
Possible patches for master (2.37 KB, patch)
2016-10-10 15:48 UTC, Stefan Metzmacher
no flags Details
Patches for v4-5-test (5.83 KB, text/plain)
2016-10-13 08:15 UTC, Stefan Metzmacher
jra: review+
metze: review? (gd)
Details
Patches for v4-4-test (5.83 KB, text/plain)
2016-10-13 08:17 UTC, Stefan Metzmacher
jra: review+
metze: review? (gd)
Details
Patches for v4-3-test (5.83 KB, text/plain)
2016-10-13 08:19 UTC, Stefan Metzmacher
jra: review+
metze: review? (gd)
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Klaus Braun 2016-10-08 12:57:11 UTC
Created attachment 12555 [details]
gss_init_sec_context failed with [ The context has expired: Success]

Hi

I'm using samba as an AD Domain Member. After a fresh install of 4.4.6
everything works like expected.

But after 10 hours it seems as if winbind is not able to refresh tickets. 
Logins after 10 hours with "smbclient ... -d8"  usually takes about 20 seconds
hanging at NTLMSSP_NEGOTIATE_KEY_EXCH. During the next 5 minutes login is fine, but then again it takes 20 seconds. Restarting winbindd resolves the
problem for the next 10 hours.

In the correlated log.wb-MyDOMAIN at level 10 I see I see entries like:

  gss_init_sec_context failed with [ The context has expired: Success]
/source3/libads/sasl.c:785(ads_sasl_spnego_bind)
  kinit succeeded but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error occurred.

Attached you will find the whole bunch of logs. 

For testing I compiled samba 4.4.6 using --with-system-mitkrb5 (version 1.14.4) which works fine. Another test with version 4.5.0 and embedded heimdal build however shows the same problem mentioned above.

The samba version I used before upgrading was 4.2.14 and it was working OK.

Any help would be appreciated.

Regards

Klaus
Comment 1 Stefan Metzmacher 2016-10-10 07:54:50 UTC
Can you check if 4.4.5 doesn't have the problem?

If so I assume the patches from bug #12007 are the problem.
Comment 2 Jordi MORILLO 2016-10-10 10:22:41 UTC
Same problem here since I upgrade from 4.4.5 to 4.4.6.
I've just downgraded 1 of my member server to 4.4.5... Will see in 10 hours if problem occurs.
Comment 3 Klaus Braun 2016-10-10 13:10:05 UTC
Will be checked with a fresh install of 4.4.5. Results tomorrow.
Comment 4 Stefan Metzmacher 2016-10-10 13:25:50 UTC
(In reply to klaus.braun from comment #3)

I was able to reproduce the problem. I'm pretty sure that 4.4.5
doesn't have that problem.

The problem is that heimdal doesn't seem to do an implicit
krb5_cc_destroy() on kinit
Comment 5 Stefan Metzmacher 2016-10-10 15:48:44 UTC
Created attachment 12560 [details]
Possible patches for master
Comment 6 Ralph Böhme 2016-10-10 15:58:58 UTC
Comment on attachment 12560 [details]
Possible patches for master

I believe you probably attached the wrong patch?
Comment 7 Jordi MORILLO 2016-10-10 17:20:28 UTC
Here is detailed log of winbind process after 10 hours (debug level 9):

get_dc_list: returning 1 ip addresses in an ordered list
get_dc_list: 10.14.76.201:389
check_negative_conn_cache returning result 0 for domain pr.educationetformation.fr server 10.14.76.201
ads_try_connect: sending CLDAP request to 10.14.76.201 (realm: pr.educationetformation.fr)
Successfully contacted LDAP server 10.14.76.201
sitename_fetch: Returning sitename for pr.educationetformation.fr: "SaintEtienneDuRouvray"
ads_dc_name: using server='DC113.PR.EDUCATIONETFORMATION.FR' IP=10.14.76.201
ads_try_connect: sending CLDAP request to 10.14.76.201 (realm: pr.educationetformation.fr)
Successfully contacted LDAP server 10.14.76.201
Connected to LDAP server dc113.pr.educationetformation.fr
KDC time offset is 0 seconds
Found SASL mechanism GSS-SPNEGO
ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2
ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2
ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10
Starting GENSEC mechanism spnego
Starting GENSEC submechanism gse_krb5
gss_init_sec_context failed with [ The context has expired: Success]
SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: NT_STATUS_INTERNAL_ERROR
kinit succeeded but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error occurred.
ads_connect for domain PR failed: An internal error occurred.
Finished processing child request 59
Comment 8 Jordi MORILLO 2016-10-10 19:13:38 UTC
(In reply to Jordi MORILLO from comment #2)
4.4.5 is running perfectly after 10 hours.
I have downgraded all my member servers
Comment 9 Klaus Braun 2016-10-11 08:15:25 UTC
(In reply to klaus.braun from comment #3)
Same here. No such Problems when using 4.4.5
Comment 10 Timo 2016-10-11 13:24:57 UTC
Same Problems here.

Sernet-Packages
Samba AD-Domain-Controller
Samba Domain-Member (File-Server)

Since 4.4.6 (last week) problems as described. No probs before!

log.winbindd-idmap
  gss_init_sec_context failed with [ The context has expired: Success]
  SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: NT_STATUS_INTERNAL_ERROR
  kinit succeeded but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error occurred.
  ads_connect for domain ds failed: An internal error occurred.
  ADS uninitialized: An internal error occurred.

log.winbindd  
  trustdom_list_done: Could not receive trustdoms
Comment 11 Stefan Metzmacher 2016-10-13 08:15:29 UTC
Created attachment 12565 [details]
Patches for v4-5-test
Comment 12 Stefan Metzmacher 2016-10-13 08:17:31 UTC
Created attachment 12566 [details]
Patches for v4-4-test
Comment 13 Stefan Metzmacher 2016-10-13 08:19:25 UTC
Created attachment 12567 [details]
Patches for v4-3-test

These are regression fixes for changes already in v4-3-test (scheduled for the last 4.3 maintenance release)
Comment 14 Klaus Braun 2016-10-13 15:40:07 UTC
(In reply to Stefan Metzmacher from comment #12)
Thanks. Is in test for 4.4.6. Results tomorrow.
Comment 15 Jeremy Allison 2016-10-13 20:14:06 UTC
Re-assigning to Karolin for integration in 4.5.next, 4.4.next, 4.3.next.
Comment 16 Klaus Braun 2016-10-14 08:24:27 UTC
(In reply to Klaus Braun from comment #14)
Works for 4.4.6. Thanks again.
Comment 17 Karolin Seeger 2016-10-20 08:43:16 UTC
(In reply to Jeremy Allison from comment #15)
Pushed to autobuild-v4-{5,4,3}-test.
Comment 18 Karolin Seeger 2016-10-25 07:48:59 UTC
(In reply to Karolin Seeger from comment #17)
Pushed to all branches.
Closing out bug report.

Thanks!