Monday, August 30, 2021

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

On 16-08-2021 11:34, Thierry Bordaz wrote:
> 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

Thanks Thierry, for the confirmation. At least I now know that I can safely ignore
this message.

The deadlock policy is currently set to 9. I'll change it to 6 and see if the
messages still happen.

>
>
>>
>>>
>>>>
>>>> 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