Description of problem: There appears to be a race failing when the DNA Plugin attempts to make a uid range replication request backed by gssapi. Version-Release number of selected component (if applicable): 389-ds-base-libs-1.2.10-0.5.a5.fc15.x86_64 389-ds-base-1.2.10-0.5.a5.fc15.x86_64 How reproducible: 100% Steps to Reproduce: 1. Install IPA Server (ipa-server-install) 2. Prepare Replica (ipa-replica-prepare replica-hostname) 3. Transfer resulting replica-hostname.gpg 4. Install Replica (ipa-replica-install replica-hostname.gpg) 5. kinit admin 6. Attempt to create new user (ipa user-add test) Actual results: ipa: ERROR: Operations error: Allocation of a new value for range cn=posix ids,cn=distributed numeric assignment plugin,cn=plugins,cn=config failed! Unable to proceed. Expected results: Expected new user to be added and range to be transferred. Additional info:
Created attachment 534505 [details] Replica Server's 389 DS Error log
Looks like there is some problem with two threads attempting to do krb auth to the same server at the same time using the same credentials the first thread comes in - it creates a new memory cache then the other thread hits the krb code and sees an existing mem cache then the first thread comes back and has the bind error Looks like the first thread is attempting to use the kerberos credentials from the cache while the other thread is accessing those same credentials and that bubbles up to the ldap_sasl_bind layer as error -1 perhaps the big krb5_lock is not big enough may have to expand the scope of the mutex to include the entire slapd_ldap_sasl_interactive_bind() function
2 threads should be able to use the same credential cache even at the same time. The only thing is that they should use separate kerberos contexts. Do we know if the krb context is shared by chance ?
(In reply to comment #3) > 2 threads should be able to use the same credential cache even at the same > time. > The only thing is that they should use separate kerberos contexts. > Do we know if the krb context is shared by chance ? Yes, it is shared. We create a memory cache (a kerberos MEMORY: cache, managed by the kerberos code, not our code) of the credentials so we don't have to do a kinit every time we connect. We already knew there were some thread safety issues with this, therefore we added a lock around the function that deals with the memory cache. However, it looks as though we need to make the lock include the entire call to slapi_ldap_interactive_bind() because that code may use the kerberos credentials in the multiple bind stages, outside of our code that gets/sets the kerberos credentials. Either that, or just not attempt to cache the credentials at all.
(In reply to comment #4) > (In reply to comment #3) > > 2 threads should be able to use the same credential cache even at the same > > time. > > The only thing is that they should use separate kerberos contexts. > > Do we know if the krb context is shared by chance ? > > Yes, it is shared. We create a memory cache (a kerberos MEMORY: cache, managed > by the kerberos code, not our code) of the credentials so we don't have to do a > kinit every time we connect. We already knew there were some thread safety > issues with this, therefore we added a lock around the function that deals with > the memory cache. However, it looks as though we need to make the lock include > the entire call to slapi_ldap_interactive_bind() because that code may use the > kerberos credentials in the multiple bind stages, outside of our code that > gets/sets the kerberos credentials. > > Either that, or just not attempt to cache the credentials at all. Rich, a kerberos context and a emmory cache are 2 separate things. You can share memory caches w/o any issue (in theory) because libkrb5 does it's own locking to access credential caches. But it cannot properly work if you share the kerberos context between multiple threads. Locking around slapi_ldap_interactive_bind() may be a major performance impact. And shouldn't be necessary as internally ldap->sasl->gssapi should create their own krb context not shared between multiple invocations. I think this maybe an actual krb5 bug if you are not using a share krb5_context, perhaps should be reassigned to krb5 for more investigation ? Any chance we can get a simple reproducer with multiple binds being performed in parallel to see if it triggers any bug in there ?
While the logs still indicate the same failures, the cli problem itself seems to manifest when _delay_ is present. Locally the errors generate, but the new user creation succeeds. When attempting to replicate from california to las vegas, or any other external location, the cli problem occurs in conjunction with the errors. This along with Rich's findings on kerberos race might explain why this problem has been difficult to reproduce.
(In reply to comment #5) > (In reply to comment #4) > > (In reply to comment #3) > > > 2 threads should be able to use the same credential cache even at the same > > > time. > > > The only thing is that they should use separate kerberos contexts. > > > Do we know if the krb context is shared by chance ? > > > > Yes, it is shared. We create a memory cache (a kerberos MEMORY: cache, managed > > by the kerberos code, not our code) of the credentials so we don't have to do a > > kinit every time we connect. We already knew there were some thread safety > > issues with this, therefore we added a lock around the function that deals with > > the memory cache. However, it looks as though we need to make the lock include > > the entire call to slapi_ldap_interactive_bind() because that code may use the > > kerberos credentials in the multiple bind stages, outside of our code that > > gets/sets the kerberos credentials. > > > > Either that, or just not attempt to cache the credentials at all. > > Rich, a kerberos context and a emmory cache are 2 separate things. You can > share memory caches w/o any issue (in theory) because libkrb5 does it's own > locking to access credential caches. But it cannot properly work if you share > the kerberos context between multiple threads. The kerberos context is not explicitly shared in the 389 code. However, looking at the krb 1.6 code, the memory cache was just a simple linked list which was accessed without locking. I don't know if that has changed since 1.6. > > Locking around slapi_ldap_interactive_bind() may be a major performance impact. I don't think so, at least, it should not impact performance any more than the current mutex in set_krb5_creds(). > And shouldn't be necessary as internally ldap->sasl->gssapi should create their > own krb context not shared between multiple invocations. See above - has this changed since krb 1.6? > > I think this maybe an actual krb5 bug if you are not using a share > krb5_context, perhaps should be reassigned to krb5 for more investigation ? It has always been an implicit assumption that the krb5 code is not very thread safe, so it is up to the application programmer to provide appropriate thread safety. > > Any chance we can get a simple reproducer with multiple binds being performed > in parallel to see if it triggers any bug in there ? Any volunteers to write such a test program?
Just tried a test on RHEL6.2 - 3 way MMR - using GSSAPI everywhere - no problems. I have an F-16 VM so I'm going to try on that platform. I'm also going to throw DNA into the mix with the 3-way MMR to see if it has something to do with DNA.
Can't reproduce on F-16 either. JR - when you got the problem - was this in a VM or a bare metal machine? Any chance you could attempt to reproduce on F-16? How large is your database? Number of entries?
This is bare metal Production Servers/ I was able to recreate the problems on F15 VM's with an empty database with only the stock entries that FreeIPA installs. What versions of FreeIPA and 389-ds-base were you testing against? My issue is with FreeIPA 2.1.3 & 389 1.2.10-0.5 and 1.2.10-0.4 I can try an F16 install from ISO, but I'm not sure what is different between 15 & 16 beside freeipa & 389-ds-base that would manifest this problem. The /var/log/slapd-DOMAIN-COM/error log catches the error 100% of the time on fresh brand new installs. Its only the functionality that varies... On local systems / VM's with low latency, the dirsrv errors are present, but the FreeIPA CLI does not produce the error, and the range DOES actually get transferred correctly... It is only the global production infrastructure that has an issue The 3 in question are in Santa Barbara, San Jose, and Las Vegas... (For reference I just performed and ldapsearch on my production directory and it returned: numEntries: 7982)
(In reply to comment #10) > This is bare metal Production Servers/ > > I was able to recreate the problems on F15 VM's with an empty database with > only the stock entries that FreeIPA installs. Ok. Good to know. > What versions of FreeIPA and 389-ds-base were you testing against? > My issue is with FreeIPA 2.1.3 & 389 1.2.10-0.5 and 1.2.10-0.4 I'm not testing with freeipa - trying to isolate the cause - much easier to set up a test environment with plain 389 - if I can't reproduce with plain 389 I will try with ipa I'm using 389-ds-base-1.2.10.a6 (pre-release code) - I've tried setting up 3-way MMR with the IPA DNA settings - all using GSSAPI - I can see the range transfers working correctly > I can try an F16 install from ISO, but I'm not sure what is different between > 15 & 16 beside freeipa & 389-ds-base that would manifest this problem. I was just wondering if you had seen the errors on a platform other than F-15 - I don't know if the issue is platform related - I will try with F-15 on a bare metal system > The /var/log/slapd-DOMAIN-COM/error log catches the error 100% of the time on > fresh brand new installs. This happens every time? > Its only the functionality that varies... On local > systems / VM's with low latency, the dirsrv errors are present, but the FreeIPA > CLI does not produce the error, and the range DOES actually get transferred > correctly... It is only the global production infrastructure that has an issue > The 3 in question are in Santa Barbara, San Jose, and Las Vegas... So on local systems/VM's with low latency, what dirsrv errors are present? Are you saying that on those systems, you can successfully add users? When you attempt to add the users and get errors, are you adding the users to the master, or to the new replica? > > (For reference I just performed and ldapsearch on my production directory and > it returned: numEntries: 7982) ok - but it sounds like you can reproduce with just the empty ipa database - so not related to database size
ipa-server-install --idstart=3000 --idmax=50000 is what sets the dna values.
Upstream ticket: https://fedorahosted.org/389/ticket/12
Still cannot reproduce 1) installed latest freeipa-server on F-15 and F-16 on VMs 2) ran on F-15 ipa-server-install -r TESTDOMAIN.COM -n testdomain.com -p password -a password --hostname=f15x8664.testdomain.com --idstart=3000 --idmax=50000 --selfsign --no-host-dns 3) ran on F-15 ipa-replica-prepare -p password f16x8664.testdomain.com 4) scp replica-info-f16x8664.testdomain.com.gpg root.com:/var/lib/ipa 5) on F-16 - applied Martin's patches for 2139 (otherwise ipa-replica-install is b0rken on F-16) 6) on F-16 - ipa-replica-install -ddd -p password -w password --no-host-dns /var/lib/ipa/replica-info-f16x8664.testdomain.com.gpg 7) on F-16 - kinit admin 8) on F-16 - ipa user-add test First Name: Test Last Name: User user was added - no errors observed - I saw the DNA range request went successfully to F-15 from F-16 Maybe it's a timing thing? Does it happen only when the servers are connected by a WAN, and not on a local network?
Spoke with JR on IRC 1) ipa user-add fails when the servers are connected by a WAN - it works on a local network 2) you still get GSSAPI errors even though the ipa user-add succeeds on a LAN - which GSSAPI errors are those?
marking as screened because it has been cloned upstream
Fixed in version 1.2.10.a7