Thursday, August 12, 2021

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

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

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