Fedora Account System
Red Hat Associate
Red Hat Customer
Description of problem: Two tests in freeIPA testsing in ipatests/test_xmlrpc/test_automember_plugin.py are failing with some regularity. The test is trying to exercise rebuild. In order to do this the modify-ops feature needs to be disabled. The sequence of events is: 1. host is created 2. hostgroup is created 3. automember rule is created 4. condition created that would add this host to the hostgroup So since the rule was created afterward the rule isn't applied. We need to rebuild. So next this happens: 5. autoMemberProcessModifyOps is set to off 6. 389-ds is restarted 7. the ipa command automember-rebuild is called (this creates a rebuild task) The ipa command will loop until the task disappears, indicating the work is done. 8. the ipa command automember-rebuild --no-wait is called (same thing but this time it doesn't wait for the task to finish) 9. An internal view of the hostgroup is updated to indicate that the host is a member. 10. The hostgroup is retrieved from LDAP and compared to the internal view. They should match. The same test is done for user groups as well. We see one or both failing periodically with rebuild not adding the membership according to the condition. I moved the restart until after the rebuild command and haven't been able to reproduce the failure. I don't know if this is related to modify-op being off means membership is not always properly calculated or the server is still not quite up after the restart when we try to force the rebuild or the task is returning as finished when it isn't. Version-Release number of selected component (if applicable): 389-ds-base-1.4.0.22-1.fc29 How reproducible: intermittently Steps to Reproduce: 1. ipa-server-install (DNS, etc is optional) 2. kinit admin 3. pull freeipa git source 4. pytest-3 -v ipatests/test_xmlrpc/test_automember_plugin.py Actual results: Sometimes fails with AssertionError that a key is missing. This indicates that the rebuild was not complete.
Just to clarify, the issue only happens if you fire off a rebuild task with "--no-wait", then make an update that should be picked up by the rebuild task, but the rebuild task is already in progress and does not see the update, is that correct? Is step [9] adding an entry or just modifying it? If "process modifies" is off, then only add operations are picked up by the automember plugin. And are you really running the rebuild task twice (steps 7 & 8)? Or is that two separate tests? And why does "process modifies" needs to off? What fails if it is on? Sorry for all the questions - I just want to make sure I understand what is going on
(In reply to mreynolds from comment #1) > Just to clarify, the issue only happens if you fire off a rebuild task with > "--no-wait", then make an update that should be picked up by the rebuild > task, but the rebuild task is already in progress and does not see the > update, is that correct? The test right now looks like: automember_hostgroup.rebuild() automember_hostgroup.rebuild(no_wait=True) One right after the other. Why I don't know, seems like the second one would be a no-op but the test code doesn't wait for it at all. > Is step [9] adding an entry or just modifying it? If "process modifies" is > off, then only add operations are picked up by the automember plugin. The test keeps an internal representation of what it thinks the live LDAP entry should look like. The original entry lacks the memberof so after the rebuild the internal copy is updated with the memberof and then the LDAP entry is pulled and compared to see if they match. > And are you really running the rebuild task twice (steps 7 & 8)? Or is that > two separate tests? Really running it twice. > And why does "process modifies" needs to off? What fails if it is on? With modifies off it does a remove and then confirms that it indeed is still not a member (e.g. the automember rule didn't re-add it). I've never seen a failure in this part of the test. > Sorry for all the questions - I just want to make sure I understand what is > going on Keep it coming, I'm stumped too. Here is a more concise list of the commands used to generate the test: ipa hostgroup-add hg1 ipa host-add web1.example.test ipa automember-add hg1 --type hostgroup ipa automember-add-condition --type hostgroup --key fqdn --inclusive-regex='^web[1-9]' hg1 ipa hostgroup-show hg1 ldapmodify and set autoMemberProcessModifyOps=off systemctl restart dirsrv@EXAMPLE-TEST ipa automember-rebuild --type hostgroup ipa automember-rebuild --type hostgroup --no-wait ipa hostgroup-show hg1 And hg1 sometimes doesn't have web1.example.test as a member What I haven't done is look to see if it ever eventually becomes a member. I'll see if I can find that out.
(In reply to Rob Crittenden from comment #2) > > Here is a more concise list of the commands used to generate the test: > > ipa hostgroup-add hg1 > ipa host-add web1.example.test > ipa automember-add hg1 --type hostgroup > ipa automember-add-condition --type hostgroup --key fqdn > --inclusive-regex='^web[1-9]' hg1 > ipa hostgroup-show hg1 > > ldapmodify and set autoMemberProcessModifyOps=off > systemctl restart dirsrv@EXAMPLE-TEST > > ipa automember-rebuild --type hostgroup Technically the membership should be correct after this finishes. > ipa automember-rebuild --type hostgroup --no-wait > ipa hostgroup-show hg1 > > And hg1 sometimes doesn't have web1.example.test as a member > What we need is to see is the DS access and the errors log with "plugin" logging enabled (nsslapd-errorlog-level: 65536). We should be able to tell from that if the task was still running or not. Checking the errors log for "automember_rebuild_task_thread" should give us the start and stop times of each task. Maybe it is returning success too early? Waiting a few seconds after the "failure" to see if it does finish would be good to know as well.
I haven't been able to reproduce this manually yet using what I think is the same procedure. Here is what I'm running: -- ipa automember-del hg1 --type hostgroup ipa hostgroup-del hg1 ipa host-del web1.example.test ipa hostgroup-add hg1 ipa host-add web1.example.test --force ipa automember-add hg1 --type hostgroup ipa automember-add-condition --type hostgroup --key fqdn --inclusive-regex='^web[1-9]' hg1 ipa hostgroup-show hg1 ldapmodify -x -D 'cn=directory manager' -w password <<EOF dn: cn=Auto Membership Plugin,cn=plugins,cn=config changetype: modify replace: autoMemberProcessModifyOps autoMemberProcessModifyOps: off EOF systemctl restart dirsrv@EXAMPLE-TEST ipa hostgroup-show hg1 ipa automember-rebuild --type hostgroup ipa automember-rebuild --type hostgroup --no-wait ipa hostgroup-show hg1 ldapmodify -x -D 'cn=directory manager' -w password <<EOF dn: cn=Auto Membership Plugin,cn=plugins,cn=config changetype: modify replace: autoMemberProcessModifyOps autoMemberProcessModifyOps: on EOF systemctl restart dirsrv@EXAMPLE-TEST -- Basically every single time the last hostgroup-show includes web1 as a member. It is missing in the automated tests sometimes. It's quite possible I'm not quite replicating the test completely.
Created attachment 1578428 [details] errors log
Created attachment 1578429 [details] access log
The logs are showing that the task is completing before it fires off the next rebuild task. So it's not a timing issue there. Maybe there is a timing issue in the test? What if you add time.sleep(1) between the steps just as a test for now? What if you also remove the second rebuild task(--no-wait)?
I experimented both with a sleep after the no-wait and dropping the no-wait and it sure seems like the no-wait is the problem. Perhaps it is a matter of expectations on our part. Does a rebuild drop all membership and then build back up from the ground up? If so our test is borked and no wonder things are breaking.
(In reply to Rob Crittenden from comment #8) > I experimented both with a sleep after the no-wait and dropping the no-wait > and it sure seems like the no-wait is the problem. Perhaps it is a matter of > expectations on our part. > > Does a rebuild drop all membership and then build back up from the ground > up? That's exactly what it does. The first thing the task does is get a list of entries using the filter defined in the task entry. Then it clears out all the automember default and custom groups. Then it updates the membership. So while the task is running the memberships will not be correct.
Thanks, then this falls into the category: how did this ever work? Re-assigning to ipa. I'll write up a loop in the test to wait for the task to finish.
(In reply to Rob Crittenden from comment #10) > Thanks, then this falls into the category: how did this ever work? It worked before because we did not do any "cleanup" in the rebuild, now we do...
Upstream ticket: https://pagure.io/freeipa/issue/7972
Fixed upstream master: https://pagure.io/freeipa/c/7ec0976cce61f829cb53dc96581dea2c569706d4
https://www.port389.org/docs/389ds/design/automember-postop-modify-design.html
Fixed upstream ipa-4-7: https://pagure.io/freeipa/c/086e48fb700cfa6b0f762cc7119f96d96cd895b9
This message is a reminder that Fedora 29 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora 29 on 2019-11-26. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '29'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 29 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
This was included in the 4.7.3 release