Hide Forgot
I verified this is a bug, I will clone an upstream ticket.
Upstream ticket: https://fedorahosted.org/freeipa/ticket/4841
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?
Created attachment 980479 [details] Original DS errors - before fix
Created attachment 980480 [details] DS errors - after fix
Created attachment 980481 [details] Partial patch, fixing AD->IPA direction
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; }
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
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?
Justification: By this bug, activated state of accounts would mismatch between DS and AD. The mismatch causes the security issue.
See this comment for the verification steps using 389-ds-base only. https://bugzilla.redhat.com/show_bug.cgi?id=1183820#c2
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
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