Bug 1879386

Summary: cli dsconf replication monitor fails to retrieve database RUV - consumer (Unavailable) State (green) Reason (error (0)
Product: Red Hat Enterprise Linux 8 Reporter: Marc Sauton <msauton>
Component: 389-ds-baseAssignee: mreynolds
Status: CLOSED ERRATA QA Contact: RHDS QE <ds-qe-bugs>
Severity: high Docs Contact:
Priority: unspecified    
Version: 8.2CC: aadhikar, jachapma, pasik, sgouvern, spichugi, tbordaz, vashirov
Target Milestone: rcKeywords: Triaged
Target Release: 8.0Flags: pm-rhel: mirror+
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-1.4-8040020201209191204-866effaa Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2021-05-18 15:45:26 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Marc Sauton 2020-09-16 07:30:00 UTC
Description of problem:

The CLI dsconf replication monitor fails to retrieve database RUV entry from consumer
and this appears into the Cockpit web UI too
"
consumer (Unavailable) State (green) Reason (error (0)
"

the issue seem to happen in src/lib389/lib389/agreement.py
when the RUV records are fetched, none are seen, and in verbose mode:
DEBUG: Failed to retrieve database RUV entry from consumer

although there is are RUV records on both systems, access log event generated by the cli command, on supplier and consumer are similar, find one entry:

[15/Sep/2020:23:55:00.895942744 -0700] conn=68 op=1 SRCH base="dc=example,dc=test" scope=2 filter="(&(nsUniqueId=ffffffff-ffffffff-ffffffff-ffffffff)(objectClass=nstombstone))" attrs="nsds50ruv"
[15/Sep/2020:23:55:00.901886817 -0700] conn=68 op=1 RESULT err=0 tag=101 nentries=1 etime=0.006021389

and to confirm:
ldapsearch -o ldif-wrap=no -LLLx -D "cn=directory manager" -w password -b dc=example,dc=test -s sub "(&(nsUniqueId=ffffffff-ffffffff-ffffffff-ffffffff)(objectClass=nstombstone))"  nsds50ruv
dn: cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config
nsds50ruv: {replicageneration} 5ef42f3c000000010000
nsds50ruv: {replica 1 ldap://el82ds11m1:389} 5ef4ecbb000000010000 5f6138dc000000010000
nsds50ruv: {replica 2 ldap://m2.example.test:389} 5efa5cfc000000020000 5f613329000000020000


Version-Release number of selected component (if applicable):

RHEL-8.2
389-ds-base-1.4.2.12-2.module+el8dsrv+6428+6e54c518.x86_64
cockpit-389-ds-1.4.2.12-2.module+el8dsrv+6428+6e54c518.noarch


How reproducible:
yes

Steps to Reproduce:
1. have 2x mmr
2. dsconf -v m1 replication monitor --connections "192.168.122.111:389:cn=directory manager:password" "192.168.122.112:389:cn=directory manager:password" | less
3. or Cockpit web UI: "Red Hat Directory Server | Monitoring | Replication | Sync Report | Prepare | Generate Report"


Actual results:

with the dsconf cli:
...snip...
DEBUG: _gen_selector filter = (&(&(objectclass=nsds5Replica))(|(nsDS5ReplicaRoot=dc=example,dc=test)))
DEBUG: cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsDS5ReplicaRoot')
DEBUG: cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsds5replicaLastUpdateStatusJSON')
DEBUG: cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsDS5ReplicaHost')
DEBUG: cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsDS5ReplicaPort')
DEBUG: cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsDS5ReplicaRoot')
DEBUG: cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsds5replicatransportinfo')
DEBUG: _gen_selector filter = (&(&(objectclass=nsds5Replica))(|(nsDS5ReplicaRoot=dc=example,dc=test)))
DEBUG: cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsDS5ReplicaRoot')
DEBUG: cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config getVal('nsDS5ReplicaId')
DEBUG: Allocate <class 'lib389.DirSrv'> with None
DEBUG: Allocate <class 'lib389.DirSrv'> with 192.168.122.112:389
DEBUG: Allocate <class 'lib389.DirSrv'> with 192.168.122.112:389
DEBUG: open(): Connecting to uri ldap://192.168.122.112:389/
DEBUG: Using dirsrv ca certificate /etc/dirsrv/slapd-template
DEBUG: Using external ca certificate /etc/dirsrv/slapd-template
DEBUG: Using external ca certificate /etc/dirsrv/slapd-template
DEBUG: Using certificate policy 1
DEBUG: ldap.OPT_X_TLS_REQUIRE_CERT = 1
DEBUG: open(): bound as None
DEBUG: Failed to retrieve database RUV entry from consumer
...snip...
INFO: Status For Agreement: "m1tom2exampletest" (192.168.122.112:389)
Replica Enabled: on
Update In Progress: FALSE
Last Update Start: 19700101000000Z
Last Update End: 19700101000000Z
Number Of Changes Sent: 0
Number Of Changes Skipped: None
Last Update Status: Error (0) No replication sessions started since server startup
Last Init Start: 19700101000000Z
Last Init End: 19700101000000Z
Last Init Status: unavailable
Reap Active: 0
Replication Status: Not in Synchronization: supplier (5f6138dc000000010000) consumer (Unavailable) State (green) Reason (error (0) no replication sessions started since server startup)
Replication Lag Time: Unavailable


with cockpit:
Replication Status
Not in Synchronization: supplier (5f6138dc000000010000) consumer (Unavailable) State (green) Reason (error (0) no replication sessions started since server startup)


Expected results:
yes


Additional info:

access logs
...snip...
[15/Sep/2020:23:54:48.757993121 -0700] conn=67 op=30 SRCH base="cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaRoot"
[15/Sep/2020:23:54:48.763804385 -0700] conn=67 op=30 RESULT err=0 tag=101 nentries=1 etime=0.005895913
[15/Sep/2020:23:54:48.764386327 -0700] conn=67 op=31 SRCH base="dc=example,dc=test" scope=2 filter="(&(nsUniqueId=ffffffff-ffffffff-ffffffff-ffffffff)(objectClass=nstombstone))" attrs="nsds5agmtmaxcsn"
[15/Sep/2020:23:54:48.770589988 -0700] conn=67 op=31 RESULT err=0 tag=101 nentries=1 etime=0.006346208
[15/Sep/2020:23:54:48.771101008 -0700] conn=67 op=32 SRCH base="cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaHost"
[15/Sep/2020:23:54:48.776920006 -0700] conn=67 op=32 RESULT err=0 tag=101 nentries=1 etime=0.005872479
[15/Sep/2020:23:54:48.777336479 -0700] conn=67 op=33 SRCH base="cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaPort"
[15/Sep/2020:23:54:48.783213636 -0700] conn=67 op=33 RESULT err=0 tag=101 nentries=1 etime=0.005941799
[15/Sep/2020:23:54:48.783680774 -0700] conn=67 op=34 SRCH base="cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaRoot"
[15/Sep/2020:23:54:48.789755512 -0700] conn=67 op=34 RESULT err=0 tag=101 nentries=1 etime=0.006137166
[15/Sep/2020:23:54:48.790187253 -0700] conn=67 op=35 SRCH base="cn=m1tom2exampletest,cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaTransportInfo"
[15/Sep/2020:23:54:48.797795382 -0700] conn=67 op=35 RESULT err=0 tag=101 nentries=1 etime=0.007663012
[15/Sep/2020:23:54:48.798380120 -0700] conn=67 op=36 SRCH base="cn=mapping tree,cn=config" scope=2 filter="(&(&(objectClass=nsds5Replica))(|(nsDS5ReplicaRoot=dc=example,dc=test)))" attrs="distinguishedName"
[15/Sep/2020:23:54:48.804556429 -0700] conn=67 op=36 RESULT err=0 tag=101 nentries=1 etime=0.006246331
[15/Sep/2020:23:54:48.806136547 -0700] conn=67 op=37 SRCH base="cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaRoot"
[15/Sep/2020:23:54:48.812059951 -0700] conn=67 op=37 RESULT err=0 tag=101 nentries=1 etime=0.005991292
[15/Sep/2020:23:54:48.812446327 -0700] conn=67 op=38 SRCH base="cn=replica,cn=dc\3Dexample\2Cdc\3Dtest,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="nsDS5ReplicaId"
[15/Sep/2020:23:54:48.818258102 -0700] conn=67 op=38 RESULT err=0 tag=101 nentries=1 etime=0.005867439
[15/Sep/2020:23:55:00.869713063 -0700] conn=68 fd=65 slot=65 connection from 192.168.122.111 to 192.168.122.111
[15/Sep/2020:23:55:00.872655659 -0700] conn=68 op=0 BIND dn="cn=Directory Manager" method=128 version=3
[15/Sep/2020:23:55:00.894731108 -0700] conn=68 op=0 RESULT err=0 tag=97 nentries=0 etime=0.022106197 dn="cn=directory manager"
[15/Sep/2020:23:55:00.895942744 -0700] conn=68 op=1 SRCH base="dc=example,dc=test" scope=2 filter="(&(nsUniqueId=ffffffff-ffffffff-ffffffff-ffffffff)(objectClass=nstombstone))" attrs="nsds50ruv"
[15/Sep/2020:23:55:00.901886817 -0700] conn=68 op=1 RESULT err=0 tag=101 nentries=1 etime=0.006021389
[15/Sep/2020:23:55:00.905749441 -0700] conn=68 op=2 UNBIND
[15/Sep/2020:23:55:00.909549718 -0700] conn=68 op=2 fd=65 closed - U1



src/lib389/lib389/agreement.py

...
    def get_consumer_maxcsn(self, binddn=None, bindpw=None):
        """Attempt to get the consumer's maxcsn from its database RUV entry
...
        result_msg = "Unavailable"
...
        # Search for the tombstone RUV entry
        try:
            entry = consumer.search_s(suffix, ldap.SCOPE_SUBTREE,
                                      REPLICA_RUV_FILTER, ['nsds50ruv'])
            if not entry:
                self._log.debug("Failed to retrieve database RUV entry from consumer")


is it possible the consumer object is not correctly initialized?
or the types incorrect?

Comment 4 sgouvern 2020-12-14 08:54:04 UTC
With build tag 389-ds:1.4:8040020201209191204:866effaa the gating tests have a failure in dirsrvtests/tests/suites/clu/repl_monitor_test.py::test_dsconf_replication_monitor

-> marking as ASSIGNED / FailedQA and moving to ITM 7

Comment 6 sgouvern 2020-12-17 13:17:29 UTC
The failing test is a test problem.
Marking the bug as MODIFIED

Comment 10 sgouvern 2020-12-21 13:32:46 UTC
As per comment 7, marking VERIFIED on build 389-ds-base-1.4.3.16-6.module+el8.4.0+9207+729bbaca.x86_64

Comment 12 errata-xmlrpc 2021-05-18 15:45:26 UTC
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 (389-ds:1.4 bug fix and enhancement update), 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://access.redhat.com/errata/RHBA-2021:1835