Monday, August 16, 2021

[389-users] Re: Several "DB retried operation targets" messages per day

On 8/12/21 4:39 PM, Mark Reynolds wrote:
>
> On 8/12/21 10:21 AM, Kees Bakker wrote:
>> On 12-08-2021 16:00, Mark Reynolds wrote:
>>> On 8/12/21 9:57 AM, Kees Bakker wrote:
>>>> On 12-08-2021 14:21, Mark Reynolds wrote:
>>>>> On 8/12/21 5:16 AM, William Brown wrote:
>>>>>> hey there,
>>>>>>
>>>>>> Some of your messages have been bouncing or being caught in spam
>>>>>> filters due to DMARC/DNS SPF failures. That may be why no one is
>>>>>> answering.
>>>>>
>>>>> No, this was not filtered.  We have a lot of engineers on PTO at the
>>>>> moment, and the rest of us are working very hard on customer
>>>>> issues and
>>>>> other important deadlines.  We can't always give timely responses to
>>>>> community questions...
>>>>
>>>> Thanks Mark,
>>>>
>>>> Sorry to put the pressure on you and the team.
>>>>
>>>>>
>>>>> Looking at the code these "warning" messages just mean that a DB
>>>>> retry
>>>>> had occurred and an operation was retried, but that operation was
>>>>> already in the Content Sync Plugin pending list.  It is a harmless
>>>>> message, and perhaps should not even be logged at the default logging
>>>>> level.
>>>>
>>>> OK.
>>>> As harmless as it may be, why does it happen to me?
>>> Story of my life...
>>
>> :-)
>>
>>>> Our system is fairly
>>>> small scale. The warnings are always triggered due to DNS updates, via
>>>> DHCP
>>>> updates. Just 100+ DHCP clients. I would expect that you would see
>>>> this on every
>>>> FreeIPA system. If not, then something might be fishy with our system.
>>>
>>> If you had DB deadlock/DB retry errors/warnings in the main
>>> database, it
>>> could cause these Content Sync warnings as a side effect.  Are you
>>> still
>>> seeing these warning messages?
>>
>> No, those deadlocks were a one-time event when we deleted a lot of
>> members from a user group. I haven't seen deadlocks since.
>>
>> The DB retried messages just happen a few times per day. I don't see an
>> obvious pattern.
>
> The engineer who wrote the Content Sync "Pending Llist" code is on
> vacation, when he gets back I'll have him follow up on this. But
> looking at the code everything is functioning properly.  The plugin
> correctly handled a problem with the DB, which is good, but it logged
> that message which is alarming...
>
> I think those warning messages should be moved to plugin logging
> instead of default logging, or change the severity level from WARN to
> INFO.  We'll see...
>
> Mark


I fully agree with Mark explanations and suggested fix.
IPA updates are prone to trigger additional internal updates and to
create conflicts (deadlock) at DB level. The resolution of those DB
deadlock is done via retry of the update. In such case the update is
already present in the pending list and there is no need to add it
again. This message is erroneously alarming and should be move to INFO
or only logged with plugin level.

What is the deadlock policy on the two centos systems ? You may try to
run with nsslapd-db-deadlock-policy=6 (priority to writers) and check if
those messages still happen

regards
thierry


>
>>
>>>
>>> Mark
>>>
>>>>
>>>>>
>>>>> Regards,
>>>>>
>>>>> Mark
>>>>>
>>>>>>
>>>>>>> On 12 Aug 2021, at 16:57, Kees Bakker <keesb@ghs.com> wrote:
>>>>>>>
>>>>>>> Isn't there anyone out there who can comment?
>>>>>>>
>>>>>>>
>>>>>>> On 04-08-2021 10:50, Kees Bakker wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> (( This was also reported as an issue at github [1], but there
>>>>>>>> isn't much activity there. ))
>>>>>>>>
>>>>>>>> Each day there several messages with "WARN - content-sync-plugin -
>>>>>>>> sync_update_persist_betxn_pre_op ...". It is unclear why they show
>>>>>>>> up.
>>>>>>>>
>>>>>>>> Briefly about the setup.
>>>>>>>> This is in a IPA deployment. We have three masters/replicas in a
>>>>>>>> triangular topology, A-B, B-C, C-A.
>>>>>>>> The systems are called: rotte, linge and iparep4.
>>>>>>>>
>>>>>>>> rotte is CentOS 7, with 389-ds-base-1.3.9.1-13.el7_7.x86_64
>>>>>>>> linge and iparep4 are CentOS 8 Stream, with
>>>>>>>> 389-ds-base-1.4.3.23-2.module_el8.5.0+835+5d54734c.x86_64
>>>>>>>>
>>>>>>>> The messages seem to have a relation to DNS updates triggered by a
>>>>>>>> DHCP server. These
>>>>>>>> updates come in on rotte, the CentOS7 system. Next, they get
>>>>>>>> replicated to the two CentOS
>>>>>>>> systems.
>>>>>>>>
>>>>>>>> At least a few times per day, on the two CentOS system I see the
>>>>>>>> following. Even though
>>>>>>>> they are just(?) warnings, I still don't like it.
>>>>>>>>
>>>>>>>>
>>>>>>>> aug 03 15:47:20 iparep4.example.com ns-slapd[485]:
>>>>>>>> [03/Aug/2021:15:47:20.474879344 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "dc=example,dc=com" (op=0x7efdcfc59600
>>>>>>>> idx_pl=0) => op not changed in PL
>>>>>>>> aug 03 20:31:12 iparep4.example.com ns-slapd[485]:
>>>>>>>> [03/Aug/2021:20:31:12.981645921 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=600749,cn=changelog"
>>>>>>>> (op=0x7efdf8310200 idx_pl=1) => op not changed in PL
>>>>>>>> aug 03 20:31:44 iparep4.example.com ns-slapd[485]:
>>>>>>>> [03/Aug/2021:20:31:44.287299445 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=600773,cn=changelog"
>>>>>>>> (op=0x7efe0a763000 idx_pl=1) => op not changed in PL
>>>>>>>> aug 03 20:36:40 iparep4.example.com ns-slapd[485]:
>>>>>>>> [03/Aug/2021:20:36:40.890527828 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=600785,cn=changelog"
>>>>>>>> (op=0x7efe14014400 idx_pl=1) => op not changed in PL
>>>>>>>> aug 04 00:09:22 iparep4.example.com ns-slapd[485]:
>>>>>>>> [04/Aug/2021:00:09:22.697622835 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets
>>>>>>>> "idnsName=rly8a-lyon,idnsname=example.com.,cn=dns,dc=example,dc=com"
>>>>>>>>
>>>>>>>> (op=0x7efe14014200 idx_pl=0) => op not changed in PL
>>>>>>>> aug 04 00:10:24 iparep4.example.com ns-slapd[485]:
>>>>>>>> [04/Aug/2021:00:10:24.370023104 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=601866,cn=changelog"
>>>>>>>> (op=0x7efde0304400 idx_pl=1) => op not changed in PL
>>>>>>>> aug 04 00:27:39 iparep4.example.com ns-slapd[485]:
>>>>>>>> [04/Aug/2021:00:27:39.369751746 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=601970,cn=changelog"
>>>>>>>> (op=0x7efe0a763000 idx_pl=1) => op not changed in PL
>>>>>>>> aug 04 00:28:58 iparep4.example.com ns-slapd[485]:
>>>>>>>> [04/Aug/2021:00:28:58.163832176 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=602032,cn=changelog"
>>>>>>>> (op=0x7efdfbb8d200 idx_pl=1) => op not changed in PL
>>>>>>>> aug 04 03:02:39 iparep4.example.com ns-slapd[485]:
>>>>>>>> [04/Aug/2021:03:02:39.646642606 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "dc=example,dc=com" (op=0x7efe0c265000
>>>>>>>> idx_pl=0) => op not changed in PL
>>>>>>>> aug 04 05:38:21 iparep4.example.com ns-slapd[485]:
>>>>>>>> [04/Aug/2021:05:38:21.334053200 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets
>>>>>>>> "idnsName=ghprobe35792,idnsname=example.com.,cn=dns,dc=example,dc=com"
>>>>>>>>
>>>>>>>> (op=0x7efe9c6d8a00 idx_pl=0) => op not changed in PL
>>>>>>>>
>>>>>>>>
>>>>>>>> Aug 03 11:38:23 linge.example.com ns-slapd[282944]:
>>>>>>>> [03/Aug/2021:11:38:23.090286378 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=359984,cn=changelog"
>>>>>>>> (op=0x7fd390ec3a00 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 03 14:36:39 linge.example.com ns-slapd[282944]:
>>>>>>>> [03/Aug/2021:14:36:39.798593691 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=360832,cn=changelog"
>>>>>>>> (op=0x7fd36532ea00 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 03 15:00:45 linge.example.com ns-slapd[282944]:
>>>>>>>> [03/Aug/2021:15:00:45.104018419 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "dc=example,dc=com" (op=0x7fd39c221800
>>>>>>>> idx_pl=0) => op not changed in PL
>>>>>>>> Aug 03 17:09:45 linge.example.com ns-slapd[282944]:
>>>>>>>> [03/Aug/2021:17:09:45.881468406 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=361533,cn=changelog"
>>>>>>>> (op=0x7fd35c1f0c00 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 03 17:42:13 linge.example.com ns-slapd[282944]:
>>>>>>>> [03/Aug/2021:17:42:13.223390704 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=361773,cn=changelog"
>>>>>>>> (op=0x7fd39d210800 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 03 19:09:44 linge.example.com ns-slapd[282944]:
>>>>>>>> [03/Aug/2021:19:09:44.298497387 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=362107,cn=changelog"
>>>>>>>> (op=0x7fd390e15200 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 04 01:42:13 linge.example.com ns-slapd[282944]:
>>>>>>>> [04/Aug/2021:01:42:13.581042356 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=364294,cn=changelog"
>>>>>>>> (op=0x7fd375366000 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 04 03:10:25 linge.example.com ns-slapd[282944]:
>>>>>>>> [04/Aug/2021:03:10:25.655556357 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=364690,cn=changelog"
>>>>>>>> (op=0x7fd353072000 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 04 07:08:40 linge.example.com ns-slapd[282944]:
>>>>>>>> [04/Aug/2021:07:08:40.618202412 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets "changenumber=365854,cn=changelog"
>>>>>>>> (op=0x7fd3a062ee00 idx_pl=1) => op not changed in PL
>>>>>>>> Aug 04 10:25:19 linge.example.com ns-slapd[282944]:
>>>>>>>> [04/Aug/2021:10:25:19.410683924 +0200] - WARN -
>>>>>>>> content-sync-plugin - sync_update_persist_betxn_pre_op - DB
>>>>>>>> retried operation targets
>>>>>>>> "idnsname=example.com.,cn=dns,dc=example,dc=com"
>>>>>>>> (op=0x7fd3cc00a200 idx_pl=0) => op not changed in PL
>>>>>>>>
>>>>>>>>
>>>>>>>> [1] https://github.com/389ds/389-ds-base/issues/4842
>>>>>>>> -- Kees
>>>>>>>> _______________________________________________
>>>>>>>> 389-users mailing list -- 389-users@lists.fedoraproject.org
>>>>>>>> To unsubscribe send an email to
>>>>>>>> 389-users-leave@lists.fedoraproject.org
>>>>>>>> Fedora Code of Conduct:
>>>>>>>> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
>>>>>>>> List Guidelines:
>>>>>>>> https://fedoraproject.org/wiki/Mailing_list_guidelines
>>>>>>>> List Archives:
>>>>>>>> https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproject.org
>>>>>>>>
>>>>>>>> Do not reply to spam on the list, report it:
>>>>>>>> https://pagure.io/fedora-infrastructure
>>>>>>> _______________________________________________
>>>>>>> 389-users mailing list -- 389-users@lists.fedoraproject.org
>>>>>>> To unsubscribe send an email to
>>>>>>> 389-users-leave@lists.fedoraproject.org
>>>>>>> Fedora Code of Conduct:
>>>>>>> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
>>>>>>> List Guidelines:
>>>>>>> https://fedoraproject.org/wiki/Mailing_list_guidelines
>>>>>>> List Archives:
>>>>>>> https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproject.org
>>>>>>>
>>>>>>> Do not reply to spam on the list, report it:
>>>>>>> https://pagure.io/fedora-infrastructure
>>>>>> --
>>>>>> Sincerely,
>>>>>>
>>>>>> William Brown
>>>>>>
>>>>>> Senior Software Engineer, Identity and Access Management
>>>>>> SUSE Labs, Australia
>>>>>> _______________________________________________
>>>>>> 389-users mailing list -- 389-users@lists.fedoraproject.org
>>>>>> To unsubscribe send an email to
>>>>>> 389-users-leave@lists.fedoraproject.org
>>>>>> Fedora Code of Conduct:
>>>>>> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
>>>>>> List Guidelines:
>>>>>> https://fedoraproject.org/wiki/Mailing_list_guidelines
>>>>>> List Archives:
>>>>>> https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproject.org
>>>>>>
>>>>>> Do not reply to spam on the list, report it:
>>>>>> https://pagure.io/fedora-infrastructure
>>>>>
>>>>> --
>>>>> Directory Server Development Team
>>>>> _______________________________________________
>>>>> 389-users mailing list -- 389-users@lists.fedoraproject.org
>>>>> To unsubscribe send an email to
>>>>> 389-users-leave@lists.fedoraproject.org
>>>>> Fedora Code of Conduct:
>>>>> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
>>>>> List Guidelines:
>>>>> https://fedoraproject.org/wiki/Mailing_list_guidelines
>>>>> List Archives:
>>>>> https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproject.org
>>>>>
>>>>> Do not reply to spam on the list, report it:
>>>>> https://pagure.io/fedora-infrastructure
>>>> _______________________________________________
>>>> 389-users mailing list -- 389-users@lists.fedoraproject.org
>>>> To unsubscribe send an email to
>>>> 389-users-leave@lists.fedoraproject.org
>>>> Fedora Code of Conduct:
>>>> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
>>>> List Guidelines:
>>>> https://fedoraproject.org/wiki/Mailing_list_guidelines
>>>> List Archives:
>>>> https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproject.org
>>>>
>>>> Do not reply to spam on the list, report it:
>>>> https://pagure.io/fedora-infrastructure
>>>
>>> --
>>> Directory Server Development Team
>>>
>>
_______________________________________________
389-users mailing list -- 389-users@lists.fedoraproject.org
To unsubscribe send an email to 389-users-leave@lists.fedoraproject.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproject.org
Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure

No comments:

Post a Comment