Re: Several "DB retried operation targets" messages per day

[Kees Bakker <keesb@xxxxxxx>]

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@xxxxxxx> 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > > > To unsubscribe send an email to
> > > > > > > > > 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > > >
> > > > > > > > > Do not reply to spam on the list, report it:
> > > > > > > > > https://pagure.io/fedora-infrastructure
> > > > > > > > _______________________________________________
> > > > > > > > 389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > > To unsubscribe send an email to
> > > > > > > > 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > >
> > > > > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > To unsubscribe send an email to
> > > > > > > 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > >
> > > > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > To unsubscribe send an email to
> > > > > > 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > >
> > > > > > Do not reply to spam on the list, report it:
> > > > > > https://pagure.io/fedora-infrastructure
> > > > > _______________________________________________
> > > > > 389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > To unsubscribe send an email to
> > > > > 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
> > > > >
> > > > > 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@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
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@xxxxxxxxxxxxxxxxxxxxxxx
Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure