Bugzilla will be upgraded to version 5.0. The upgrade date is tentatively scheduled for 2 December 2018, pending final testing and feedback.
Bug 1182477 - User enable/disable does not sync with ipawinsyncacctdisable set to both
User enable/disable does not sync with ipawinsyncacctdisable set to both
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: 389-ds-base (Show other bugs)
7.1
Unspecified Unspecified
unspecified Severity unspecified
: rc
: ---
Assigned To: IPA Maintainers
Namita Soman
: Regression
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-01-15 03:58 EST by Steeve Goveas
Modified: 2015-03-05 04:40 EST (History)
9 users (show)

See Also:
Fixed In Version: 389-ds-base-1.3.3.1-12.el7
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-03-05 04:40:22 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Original DS errors - before fix (68.31 KB, application/x-gzip)
2015-01-15 06:51 EST, Martin Kosek
no flags Details
DS errors - after fix (36.19 KB, application/x-gzip)
2015-01-15 06:51 EST, Martin Kosek
no flags Details
Partial patch, fixing AD->IPA direction (1.99 KB, patch)
2015-01-15 06:52 EST, Martin Kosek
no flags Details | Diff


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2015:0416 normal SHIPPED_LIVE Important: 389-ds-base security, bug fix, and enhancement update 2015-03-05 09:26:33 EST

  None (edit)
Comment 3 Martin Kosek 2015-01-15 06:40:56 EST
I verified this is a bug, I will clone an upstream ticket.
Comment 4 Martin Kosek 2015-01-15 06:42:17 EST
Upstream ticket:
https://fedorahosted.org/freeipa/ticket/4841
Comment 5 Martin Kosek 2015-01-15 06:50:48 EST
I investigated this bug, I personally doubt it is a regression from 7.0 unless something changed in the Directory Server - the last update was done in
https://fedorahosted.org/freeipa/ticket/3007
which is in older RHELs. Rich or Noriko, any idea what could be the root cause?

When checking plugins debug log, I see following pattern, being the probable root cause:

[14/Jan/2015:18:12:52 -0500] ipa-winsync - --> ipa_winsync_pre_ds_mod_user_cb -- begin
[14/Jan/2015:18:12:52 -0500] ipa-winsync - <-- sync_acct_disable - the AD entry corresponding to [uid=duser,cn=users,cn=accounts,dc=mkosek-f21,dc=test] is NULL - skipping
[14/Jan/2015:18:12:52 -0500] ipa-winsync - do_force_sync - forcing sync of AD entry [(none)] with DS entry [uid=duser,cn=users,cn=accounts,dc=mkosek-f21,dc=test]
[14/Jan/2015:18:12:52 -0500] ipa-winsync - <-- ipa_winsync_pre_ds_mod_user_cb -- end

See origin DS errors log for full log.

After I fixed the calls in the code, from

~~~~~~~
    sync_acct_disable(cbdata, rawentry, ds_entry, ACCT_DISABLE_TO_DS,
                      ds_entry, NULL, NULL);
~~~~~~~

to

~~~~~~~
    sync_acct_disable(cbdata, ad_entry, ds_entry, ACCT_DISABLE_TO_DS,
                      ds_entry, NULL, NULL);
~~~~~~~

at least the AD->IPA side started working, see the attached patch and second log.

However, IPA->AD side is still not working as I could not update this part:

~~~~~~~
    LOG("--> ipa_winsync_pre_ad_mod_user_mods_cb -- begin\n");

    /* wrap the modstosend in a Slapi_Mods for convenience */
    smods = slapi_mods_new();
    slapi_mods_init_passin(smods, *modstosend);
    sync_acct_disable(cbdata, rawentry, (Slapi_Entry *)ds_entry,
                      ACCT_DISABLE_TO_AD, NULL, smods, NULL);
~~~~~~~

as I did not have access to ad_entry there. Any idea how to fix it?
Comment 6 Martin Kosek 2015-01-15 06:51:27 EST
Created attachment 980479 [details]
Original DS errors - before fix
Comment 7 Martin Kosek 2015-01-15 06:51:56 EST
Created attachment 980480 [details]
DS errors - after fix
Comment 8 Martin Kosek 2015-01-15 06:52:34 EST
Created attachment 980481 [details]
Partial patch, fixing AD->IPA direction
Comment 9 Noriko Hosoi 2015-01-15 13:25:09 EST
Martin,

Your code change looks familiar.  Please take a look at this ticket:
https://fedorahosted.org/389/ticket/47763

We were reported that posix plugin's modify part got broken and a patch was provided.  The patch contains the same change in your comment5 on TO_DS.

1153	 	    sync_acct_disable(cbdata, rawentry, ds_entry, ACCT_DISABLE_TO_DS, ds_entry, NULL, NULL); 
 	1206	    sync_acct_disable(cbdata, ad_entry, ds_entry, ACCT_DISABLE_TO_DS, ds_entry, NULL, NULL); 

I thought TO_AD was not affected...  If you are interested in to replace "rawentry" with "ad_entry" in this call,
    sync_acct_disable(cbdata, rawentry, (Slapi_Entry *)ds_entry,
                      ACCT_DISABLE_TO_AD, NULL, smods, NULL);

the third argument passed to the callback is "ad_entry":
void
winsync_plugin_call_pre_ad_mod_user_cb(const Repl_Agmt *ra, const Slapi_Entry *rawentry,
                                       Slapi_Entry *ad_entry, Slapi_Entry *ds_entry,
                                       Slapi_Mods *smods, int *do_modify)
{
 WINSYNC_PLUGIN_CALL_PLUGINS_COOKIE_BEGIN(WINSYNC_PLUGIN_PRE_AD_MOD_USER_CB,winsync_pre_mod_cb,thefunc)
        (*thefunc)(cookie, rawentry, ad_entry, ds_entry, smods, do_modify);
                                     ^^^^^^^^^
    WINSYNC_PLUGIN_CALL_PLUGINS_END;

    return;
}
Comment 10 Noriko Hosoi 2015-01-15 13:31:02 EST
Please see also this bug (this is just a cloned bug).
https://bugzilla.redhat.com/show_bug.cgi?id=1118060
Bug 1118060 - winsync plugin modify is broken

I'm going to add the test steps to verify enabling/disabling an account is synchronized between AD and DS.

Thanks,
--noriko
Comment 11 Martin Kosek 2015-01-16 04:12:41 EST
Ah, thanks for info. The problem as I see it is that rawentry is suddenly NULL. I assume that it was not NULL before the referred DS update as this code was not touched in IPA since the last release.

We can fix AD->DS with my patch. However, the DS->AD direction still seems broken. The callback winsync_plugin_call_pre_ad_mod_user_cb with ad_entry available is not called. Instead, ipa_winsync_pre_ad_mod_user_mods_cb is being called:

[14/Jan/2015:18:30:05 -0500] ipa-winsync - --> ipa_winsync_pre_ad_mod_user_mods_cb -- begin
[14/Jan/2015:18:30:05 -0500] ipa-winsync - <-- sync_acct_disable - the AD entry corresponding to [uid=testuser,cn=users,cn=accounts,dc=mkosek-f21,dc=test] is NULL - skipping
[14/Jan/2015:18:30:05 -0500] ipa-winsync - <-- ipa_winsync_pre_ad_mod_user_mods_cb -- end

This does not have the ad_entry available, so the sync_acct_disable fails. Can you please advise what should we change then in the ipa-winsync plugin, besides the patch already provided?
Comment 16 Noriko Hosoi 2015-01-19 14:19:03 EST
Justification: By this bug, activated state of accounts would mismatch between DS and AD.  The mismatch causes the security issue.
Comment 17 Noriko Hosoi 2015-01-20 13:41:31 EST
See this comment for the verification steps using 389-ds-base only.
https://bugzilla.redhat.com/show_bug.cgi?id=1183820#c2
Comment 19 Steeve Goveas 2015-01-27 07:09:36 EST
Verified in version
389-ds-base-1.3.3.1-13.el7.x86_64
ipa-server-4.1.0-16.el7.x86_64
sssd-ipa-1.12.2-47.el7.x86_64


::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
:: [   LOG    ] :: ipa_winsync_0009: Synchronization behaviour of account lock status
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

ipawinsyncacctdisable: both
:: [   PASS   ] :: Winsync account disable set to "both" by default 
:: [ 15:30:55 ] :: Testing with Winsync account disable set to"both"
:: [  BEGIN   ] :: Creating ldif file to reset ipawinsyncacctdisable to "both" :: actually running 'acctdisable_ldif both'
:: [   PASS   ] :: Creating ldif file to reset ipawinsyncacctdisable to "both" (Expected 0, got 0)
:: [  BEGIN   ] :: Setting disabled account to sync to both servers :: actually running 'ldapmodify -x -D "cn=Directory Manager" -w Secret123 -f acctdisable.ldif'
modifying entry "cn=ipa-winsync,cn=plugins,cn=config"

:: [   PASS   ] :: Setting disabled account to sync to both servers (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 is enabled on IPA :: actually running 'ipa user-show aduser1 | grep "Account disabled: False"'
  Account disabled: False
:: [   PASS   ] :: aduser1 is enabled on IPA (Expected 0, got 0)
:: [  BEGIN   ] :: Creating ldif file for disabling aduser1 :: actually running 'ADuser_cntrl_ldif aduser1 ads 514'
:: [   PASS   ] :: Creating ldif file for disabling aduser1 (Expected 0, got 0)
:: [  BEGIN   ] :: Disable aduser1 on AD :: actually running 'ldapmodify -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -f ADuser_cntrl.ldif'
modifying entry "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com"

:: [   PASS   ] :: Disable aduser1 on AD (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 disabled in AD :: actually running 'ldapsearch -x -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -b "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com" | grep "userAccountControl: 514"'
userAccountControl: 514
:: [   PASS   ] :: aduser1 disabled in AD (Expected 0, got 0)
:: [  BEGIN   ] :: Waiting for sync :: actually running 'sleep 30'
:: [   PASS   ] :: Waiting for sync (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'sleep 5'
:: [   PASS   ] :: Command 'sleep 5' (Expected 0, got 0)
:: [  BEGIN   ] :: After sync aduser1 disabled on IPA as well :: actually running 'ipa user-show aduser1 | grep "Account disabled: True"'
  Account disabled: True
:: [   PASS   ] :: After sync aduser1 disabled on IPA as well (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'ipa user-enable aduser1'
------------------------------
Enabled user account "aduser1"
------------------------------
:: [   PASS   ] :: Command 'ipa user-enable aduser1' (Expected 0, got 0)
:: [  BEGIN   ] :: Re-enabled aduser1 from IPA :: actually running 'ipa user-show aduser1 | grep "Account disabled: False"'
  Account disabled: False
:: [   PASS   ] :: Re-enabled aduser1 from IPA (Expected 0, got 0)
:: [  BEGIN   ] :: Giving 5 seconds to inform AD :: actually running 'sleep 5'
:: [   PASS   ] :: Giving 5 seconds to inform AD (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 is enabled in AD as well :: actually running 'ldapsearch -x -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -b "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com" | grep "userAccountControl: 512"'
userAccountControl: 512
:: [   PASS   ] :: aduser1 is enabled in AD as well (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'sleep 5'
:: [   PASS   ] :: Command 'sleep 5' (Expected 0, got 0)
:: [ 15:31:49 ] :: Testing with Winsync account disable set to "none"
:: [  BEGIN   ] :: Creating ldif file to set ipawinsyncacctdisable to none :: actually running 'acctdisable_ldif none'
:: [   PASS   ] :: Creating ldif file to set ipawinsyncacctdisable to none (Expected 0, got 0)
:: [  BEGIN   ] :: Setting disabled account to not sync to IPA :: actually running 'ldapmodify -x -D "cn=Directory Manager" -w Secret123 -f acctdisable.ldif'
modifying entry "cn=ipa-winsync,cn=plugins,cn=config"

:: [   PASS   ] :: Setting disabled account to not sync to IPA (Expected 0, got 0)
:: [  BEGIN   ] :: Disable aduser1 on AD :: actually running 'ldapmodify -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -f ADuser_cntrl.ldif'
modifying entry "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com"

:: [   PASS   ] :: Disable aduser1 on AD (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 disabled in AD :: actually running 'ldapsearch -x -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -b "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com" | grep "userAccountControl: 514"'
userAccountControl: 514
:: [   PASS   ] :: aduser1 disabled in AD (Expected 0, got 0)
:: [  BEGIN   ] :: Waiting for sync :: actually running 'sleep 30'
:: [   PASS   ] :: Waiting for sync (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'sleep 5'
:: [   PASS   ] :: Command 'sleep 5' (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 is not disabled on IPA expected :: actually running 'ipa user-show aduser1 | grep "Account disabled: False"'
  Account disabled: False
:: [   PASS   ] :: aduser1 is not disabled on IPA expected (Expected 0, got 0)
:: [ 15:32:27 ] :: Testing reverting change for ipawinsyncacctdisable does not trigger a rescan of AD
:: [  BEGIN   ] :: Creating ldif file to reset ipawinsyncacctdisable to "both" :: actually running 'acctdisable_ldif both'
:: [   PASS   ] :: Creating ldif file to reset ipawinsyncacctdisable to "both" (Expected 0, got 0)
:: [  BEGIN   ] :: Resetting disabled account to sync to both servers :: actually running 'ldapmodify -x -D "cn=Directory Manager" -w Secret123 -f acctdisable.ldif'
modifying entry "cn=ipa-winsync,cn=plugins,cn=config"

:: [   PASS   ] :: Resetting disabled account to sync to both servers (Expected 0, got 0)
:: [  BEGIN   ] :: Waiting for sync :: actually running 'sleep 30'
:: [   PASS   ] :: Waiting for sync (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'sleep 5'

MARK-LWD-LOOP -- 2015-01-27 15:32:59 --
:: [   PASS   ] :: Command 'sleep 5' (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 is still enabled on IPA after account lock status change to both. As expected :: actually running 'ipa user-show aduser1 | grep "Account disabled: False"'
  Account disabled: False
:: [   PASS   ] :: aduser1 is still enabled on IPA after account lock status change to both. As expected (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'ADuser_cntrl_ldif aduser1 ads 512'
:: [   PASS   ] :: Command 'ADuser_cntrl_ldif aduser1 ads 512' (Expected 0, got 0)
:: [  BEGIN   ] :: Re-enable aduser1 on AD :: actually running 'ldapmodify -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -f ADuser_cntrl.ldif'
modifying entry "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com"

:: [   PASS   ] :: Re-enable aduser1 on AD (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 re-enabled in AD :: actually running 'ldapsearch -x -ZZ -h squab.adrelm.com -D "CN=Administrator,CN=Users,DC=adrelm,DC=com" -w Secret123 -b "CN=aduser1 ads,CN=Users,DC=adrelm,DC=com" | grep "userAccountControl: 512"'
userAccountControl: 512
:: [   PASS   ] :: aduser1 re-enabled in AD (Expected 0, got 0)
:: [  BEGIN   ] :: Waiting for sync :: actually running 'sleep 30'
:: [   PASS   ] :: Waiting for sync (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'sleep 5'
:: [   PASS   ] :: Command 'sleep 5' (Expected 0, got 0)
:: [  BEGIN   ] :: aduser1 is enabled in IPA :: actually running 'ipa user-show aduser1 | grep "Account disabled: False"'
  Account disabled: False
:: [   PASS   ] :: aduser1 is enabled in IPA (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'sleep 10'
:: [   PASS   ] :: Command 'sleep 10' (Expected 0, got 0)
'0effef4f-b44c-46b3-8bc9-6331c6b2f860'
ipa-winsync-0009-Synchronization-behaviour-of-account-lock-status result: PASS
Comment 21 errata-xmlrpc 2015-03-05 04:40:22 EST
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2015-0416.html

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