This is an automated email from the git hooks/post-receive script.
mreynolds pushed a commit to branch 389-ds-base-1.4.0
in repository 389-ds-base.
The following commit(s) were added to refs/heads/389-ds-base-1.4.0 by this push:
new 2510147 Issue 49602 - Revise replication status messages
2510147 is described below
commit 2510147079531071e438cd57fc353905fcf84c75
Author: Mark Reynolds <mreynolds(a)redhat.com>
AuthorDate: Thu Jun 13 13:01:35 2019 -0400
Issue 49602 - Revise replication status messages
Bug Description: All agreement status messages start with "Error (##)"
followed
by a text string. Even success states start with "Error",
and
this is confusing.
Added new attributes to display the status in a JSON format
for easier parsing for applications:
replicaLastUpdateStatusJSON
replicaLastInitStatusJSON
Design Doc:
https://www.port389.org/docs/389ds/design/repl-agmt-status-design.html
https://pagure.io/389-ds-base/issue/49602
Reviewed by: firstyear(Thanks!)
---
.../tests/suites/replication/single_master_test.py | 19 +++--
ldap/schema/01core389.ldif | 2 +
ldap/servers/plugins/replication/repl5_agmt.c | 84 +++++++++++++++++++---
.../plugins/replication/repl5_protocol_util.c | 13 ++--
4 files changed, 96 insertions(+), 22 deletions(-)
diff --git a/dirsrvtests/tests/suites/replication/single_master_test.py
b/dirsrvtests/tests/suites/replication/single_master_test.py
index 1af37cc..6468869 100644
--- a/dirsrvtests/tests/suites/replication/single_master_test.py
+++ b/dirsrvtests/tests/suites/replication/single_master_test.py
@@ -23,6 +23,7 @@ from lib389._constants import (ReplicaRole, DEFAULT_SUFFIX,
REPLICAID_MASTER_1,
REPLICATION_BIND_METHOD, REPLICATION_TRANSPORT,
DEFAULT_BACKUPDIR,
RA_NAME, RA_BINDDN, RA_BINDPW, RA_METHOD,
RA_TRANSPORT_PROT,
defaultProperties)
+import json
DEBUGGING = os.getenv("DEBUGGING", default=False)
if DEBUGGING:
@@ -93,7 +94,7 @@ def test_mail_attr_repl(topo_r):
consumer.start()
log.info("Make a search for mail attribute in attempt to crash server")
- consumer.search_s(DEFAULT_SUFFIX, ldap.SCOPE_SUBTREE,
"(mail=testuser(a)redhat.com)", ["mail"])
+ c_user.get_attr_val("mail")
log.info("Make sure that server hasn't crashed")
repl.test_replication(master, consumer)
@@ -109,11 +110,13 @@ def test_lastupdate_attr_before_init(topo_nr):
1. Check nsds5replicaLastUpdateStart value
2. Check nsds5replicaLastUpdateEnd value
3. Check nsds5replicaLastUpdateStatus value
+ 4. Check nsds5replicaLastUpdateStatusJSON is parsable
:expectedresults:
1. nsds5replicaLastUpdateStart should be equal to 0
2. nsds5replicaLastUpdateEnd should be equal to 0
3. nsds5replicaLastUpdateStatus should not be equal
- to "0 Replica acquired successfully: Incremental update started"
+ to "Replica acquired successfully: Incremental update started"
+ 4. Success
"""
master = topo_nr.ins["standalone1"]
@@ -137,11 +140,15 @@ def test_lastupdate_attr_before_init(topo_nr):
with pytest.raises(Exception):
repl.wait_for_replication(master, consumer, timeout=5)
- assert agmt.get_attr_val_bytes('nsds5replicaLastUpdateStart') ==
b"19700101000000Z"
- assert agmt.get_attr_val_bytes("nsds5replicaLastUpdateEnd") ==
b"19700101000000Z"
- assert b"Replica acquired successfully" not in
agmt.get_attr_val_bytes("nsds5replicaLastUpdateStatus")
-
+ assert agmt.get_attr_val_utf8('nsds5replicaLastUpdateStart') ==
"19700101000000Z"
+ assert agmt.get_attr_val_utf8("nsds5replicaLastUpdateEnd") ==
"19700101000000Z"
+ assert "replica acquired successfully" not in
agmt.get_attr_val_utf8_l("nsds5replicaLastUpdateStatus")
+ # make sure the JSON attribute is parsable
+ json_status = agmt.get_attr_val_utf8("nsds5replicaLastUpdateStatusJSON")
+ if json_status is not None:
+ json_obj = json.loads(json_status)
+ log.debug("JSON status message: {}".format(json_obj))
if __name__ == '__main__':
# Run isolated
diff --git a/ldap/schema/01core389.ldif b/ldap/schema/01core389.ldif
index a595b76..f4123f2 100644
--- a/ldap/schema/01core389.ldif
+++ b/ldap/schema/01core389.ldif
@@ -312,6 +312,8 @@ attributeTypes: ( 2.16.840.1.113730.3.1.2341 NAME
'nsslapd-changelogmaxentries'
attributeTypes: ( 2.16.840.1.113730.3.1.2344 NAME 'nsslapd-tls-check-crl' DESC
'Check CRL when opening outbound TLS connections. Valid options are none, peer,
all.' SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 SINGLE-VALUE X-ORIGIN '389 Directory
Server' )
attributeTypes: ( 2.16.840.1.113730.3.1.2353 NAME 'nsslapd-encryptionalgorithm'
DESC 'The encryption algorithm used to encrypt the changelog' SYNTAX
1.3.6.1.4.1.1466.115.121.1.15 SINGLE-VALUE X-ORIGIN '389 Directory Server' )
attributeTypes: ( 2.16.840.1.113730.3.1.2084 NAME 'nsSymmetricKey' DESC 'A
symmetric key - currently used by attribute encryption' SYNTAX
1.3.6.1.4.1.1466.115.121.1.40 SINGLE-VALUE X-ORIGIN 'attribute encryption' )
+attributeTypes: ( 2.16.840.1.113730.3.1.2364 NAME
'nsds5replicaLastInitStatusJSON' DESC 'Netscape defined attribute type'
SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 SINGLE-VALUE NO-USER-MODIFICATION X-ORIGIN
'Netscape Directory Server' )
+attributeTypes: ( 2.16.840.1.113730.3.1.2365 NAME
'nsds5replicaLastUpdateStatusJSON' DESC 'Netscape defined attribute type'
SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 SINGLE-VALUE NO-USER-MODIFICATION X-ORIGIN
'Netscape Directory Server' )
#
# objectclasses
#
diff --git a/ldap/servers/plugins/replication/repl5_agmt.c
b/ldap/servers/plugins/replication/repl5_agmt.c
index 53e6708..8e4586d 100644
--- a/ldap/servers/plugins/replication/repl5_agmt.c
+++ b/ldap/servers/plugins/replication/repl5_agmt.c
@@ -60,7 +60,11 @@
#define DEFAULT_TIMEOUT 120 /* (seconds) default outbound LDAP connection */
#define DEFAULT_FLOWCONTROL_WINDOW 1000 /* #entries sent without acknowledgment */
#define DEFAULT_FLOWCONTROL_PAUSE 2000 /* msec of pause when #entries sent witout
acknowledgment */
-#define STATUS_LEN 1024
+#define STATUS_LEN 2048
+#define STATUS_GOOD "green"
+#define STATUS_WARNING "amber"
+#define STATUS_BAD "red"
+
struct changecounter
{
@@ -93,11 +97,13 @@ typedef struct repl5agmt
time_t last_update_start_time; /* Local start time of last update session */
time_t last_update_end_time; /* Local end time of last update session */
char last_update_status[STATUS_LEN]; /* Status of last update. Format = numeric code
<space> textual description */
+ char last_update_status_json[STATUS_LEN];
PRBool update_in_progress;
PRBool is_enabled;
time_t last_init_start_time; /* Local start time of last total init */
time_t last_init_end_time; /* Local end time of last total init */
char last_init_status[STATUS_LEN]; /* Status of last total init. Format = numeric
code <space> textual description */
+ char last_init_status_json[STATUS_LEN];
PRLock *lock;
Object *consumerRUV; /* last RUV received from the consumer - used for changelog
purging */
CSN *consumerSchemaCSN; /* last schema CSN received from the consumer */
@@ -2443,6 +2449,21 @@ agmt_set_last_init_end(Repl_Agmt *ra, time_t end_time)
}
}
+static void
+agmt_set_last_update_status_json(Repl_Agmt *ra, char *state, int ldaprc, int replrc)
+{
+ char ts[SLAPI_TIMESTAMP_BUFSIZE];
+ time_t now;
+
+ time(&now);
+ strftime(ts, sizeof ts, "%FT%TZ", gmtime(&now));
+ PR_snprintf(ra->last_update_status_json, STATUS_LEN,
+ "{\"state\": \"%s\", \"ldap_rc\":
\"%d\", \"ldap_rc_text\": \"%s\", "
+ "\"repl_rc\": \"%d\", \"repl_rc_text\":
\"%s\", \"date\": \"%s\", \"message\":
\"%s\"}",
+ state, ldaprc, ldap_err2string(ldaprc), replrc,
protocol_response2string(replrc),
+ ts, ra->last_update_status);
+}
+
void
agmt_set_last_update_status(Repl_Agmt *ra, int ldaprc, int replrc, const char *message)
{
@@ -2463,19 +2484,29 @@ agmt_set_last_update_status(Repl_Agmt *ra, int ldaprc, int replrc,
const char *m
PR_snprintf(ra->last_update_status, STATUS_LEN, "Error (%d) %s%s -
LDAP error: %s%s%s%s",
ldaprc, message ? message : "", message ? ""
: " - ",
slapi_err2string(ldaprc), replmsg ? " (" :
"", replmsg ? replmsg : "", replmsg ? ")" : "");
+ agmt_set_last_update_status_json(ra, STATUS_BAD, ldaprc, replrc);
}
/* ldaprc == LDAP_SUCCESS */
else if (replrc != 0) {
if (replrc == NSDS50_REPL_REPLICA_BUSY) {
PR_snprintf(ra->last_update_status, STATUS_LEN,
- "Error (%d) Can't acquire busy replica",
replrc);
+ "Error (%d) Can't acquire busy replica (%s)",
+ replrc, message ? message : "");
+ agmt_set_last_update_status_json(ra, STATUS_WARNING, ldaprc, replrc);
+ } else if (replrc == NSDS50_REPL_TRANSIENT_ERROR || replrc ==
NSDS50_REPL_BACKOFF) {
+ PR_snprintf(ra->last_update_status, STATUS_LEN,
+ "Error (%d) Can't acquire replica (%s)",
+ replrc, message ? message : "");
+ agmt_set_last_update_status_json(ra, STATUS_WARNING, ldaprc, replrc);
} else if (replrc == NSDS50_REPL_REPLICA_RELEASE_SUCCEEDED) {
PR_snprintf(ra->last_update_status, STATUS_LEN, "Error (0)
Replication session successful");
+ agmt_set_last_update_status_json(ra, STATUS_GOOD, ldaprc, replrc);
} else if (replrc == NSDS50_REPL_DISABLED) {
PR_snprintf(ra->last_update_status, STATUS_LEN, "Error (%d)
Incremental update aborted: "
"Replication
agreement for %s\n can not be updated while the replica is disabled.\n"
"(If the suffix is
disabled you must enable it then restart the server for replication to take
place).",
replrc, ra->long_name ? ra->long_name : "a
replica");
+ agmt_set_last_update_status_json(ra, STATUS_BAD, ldaprc, replrc);
/* Log into the errors log, as "ra->long_name" is not
accessible from the caller */
slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
"Incremental update aborted: Replication agreement for
\"%s\" "
@@ -2487,17 +2518,35 @@ agmt_set_last_update_status(Repl_Agmt *ra, int ldaprc, int replrc,
const char *m
PR_snprintf(ra->last_update_status, STATUS_LEN,
"Error (%d) Replication error acquiring replica:
%s%s(%s)",
replrc, message ? message : "", message ? "
" : "", protocol_response2string(replrc));
+ agmt_set_last_update_status_json(ra, STATUS_BAD, ldaprc, replrc);
}
} else if (message != NULL) /* replrc == NSDS50_REPL_REPLICA_READY == 0 */
{
PR_snprintf(ra->last_update_status, STATUS_LEN,
"Error (0) Replica acquired successfully: %s",
message);
+ agmt_set_last_update_status_json(ra, STATUS_GOOD, ldaprc, replrc);
} else { /* agmt_set_last_update_status(0,0,NULL) to reset agmt */
ra->last_update_status[0] = '\0';
+ ra->last_update_status_json[0] = '\0';
}
}
}
+static void
+agmt_set_last_init_status_json(Repl_Agmt *ra, char *state, int ldaprc, int replrc, int
connrc)
+{
+ char ts[SLAPI_TIMESTAMP_BUFSIZE];
+ time_t now;
+
+ time(&now);
+ strftime(ts, sizeof ts, "%FT%TZ", gmtime(&now));
+ PR_snprintf(ra->last_init_status_json, STATUS_LEN,
+ "{\"state\": \"%s\", \"ldap_rc\":
\"%d\", \"ldap_rc_text\": \"%s\", \"repl_rc\":
\"%d\", \"repl_rc_text\": \"%s\", "
+ "\"conn_rc\": \"%d\", \"conn_rc_text\":
\"%s\", \"date\": \"%s\", \"message\":
\"%s\"}",
+ state, ldaprc, ldap_err2string(ldaprc), replrc,
protocol_response2string(replrc),
+ connrc, conn_result2string(connrc), ts, ra->last_init_status);
+}
+
void
agmt_set_last_init_status(Repl_Agmt *ra, int ldaprc, int replrc, int connrc, const char
*message)
{
@@ -2523,16 +2572,16 @@ agmt_set_last_init_status(Repl_Agmt *ra, int ldaprc, int replrc,
int connrc, con
replmsg = NULL;
}
}
- PR_snprintf(ra->last_init_status, STATUS_LEN, "Error (%d) %s%sLDAP
error: %s%s%s%s%s",
+ PR_snprintf(ra->last_init_status, STATUS_LEN, "Error (%d)%s%sLDAP
error: %s%s%s%s%s",
ldaprc, message ? message : "", message ? ""
: " - ",
slapi_err2string(ldaprc), replmsg ? " - " :
"", replmsg ? replmsg : "",
connrc ? " - " : "", connrc ? connmsg :
"");
+ agmt_set_last_init_status_json(ra, STATUS_BAD, ldaprc, replrc, connrc);
}
/* ldaprc == LDAP_SUCCESS */
else if (replrc != 0) {
if (replrc == NSDS50_REPL_REPLICA_RELEASE_SUCCEEDED) {
- PR_snprintf(ra->last_init_status, STATUS_LEN, "Error (%d)
%s",
- ldaprc, "Replication session successful");
+ PR_snprintf(ra->last_init_status, STATUS_LEN, "Replication
session successful");
} else if (replrc == NSDS50_REPL_DISABLED) {
if (agmt_is_enabled(ra)) {
slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name, "Total update
aborted: "
@@ -2543,6 +2592,7 @@ agmt_set_last_init_status(Repl_Agmt *ra, int ldaprc, int replrc, int
connrc, con
"Replication
agreement for \"%s\" can not be updated while the suffix is disabled.\n"
"You must enable
it then restart the server for replication to take place).",
replrc, ra->long_name ? ra->long_name : "a
replica");
+ agmt_set_last_init_status_json(ra, STATUS_BAD, ldaprc, replrc,
connrc);
} else {
/* You do not need to restart the server after enabling the agreement
*/
slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name, "Total update
aborted: "
@@ -2551,6 +2601,7 @@ agmt_set_last_init_status(Repl_Agmt *ra, int ldaprc, int replrc, int
connrc, con
PR_snprintf(ra->last_init_status, STATUS_LEN, "Error (%d)
Total update aborted: "
"Replication
agreement for \"%s\" can not be updated while the agreement is disabled.",
replrc, ra->long_name ? ra->long_name : "a
replica");
+ agmt_set_last_init_status_json(ra, STATUS_BAD, ldaprc, replrc,
connrc);
}
} else {
PR_snprintf(ra->last_init_status, STATUS_LEN,
@@ -2558,19 +2609,21 @@ agmt_set_last_init_status(Repl_Agmt *ra, int ldaprc, int replrc,
int connrc, con
replrc, protocol_response2string(replrc),
message ? " - " : "", message ? message :
"",
connrc ? " - " : "", connrc ? connmsg :
"");
+ agmt_set_last_init_status_json(ra, STATUS_BAD, ldaprc, replrc, connrc);
}
} else if (connrc != CONN_OPERATION_SUCCESS) {
PR_snprintf(ra->last_init_status, STATUS_LEN,
"Error (%d) connection error: %s%s%s",
connrc, connmsg,
message ? " - " : "", message ? message :
"");
- } else if (message != NULL) /* replrc == NSDS50_REPL_REPLICA_READY == 0 */
- {
+ agmt_set_last_init_status_json(ra, STATUS_BAD, ldaprc, replrc, connrc);
+ } else if (message != NULL) { /* replrc == NSDS50_REPL_REPLICA_READY == 0 */
PR_snprintf(ra->last_init_status, STATUS_LEN,
- "Error (%d) %s",
- ldaprc, message);
+ "Error (%d) %s", ldaprc, message);
+ agmt_set_last_init_status_json(ra, STATUS_GOOD, ldaprc, replrc, connrc);
} else { /* agmt_set_last_init_status(0,0,NULL) to reset agmt */
- PR_snprintf(ra->last_init_status, STATUS_LEN, "Error (%d)",
ldaprc);
+ ra->last_init_status[0] = '\0';
+ ra->last_init_status_json[0] = '\0';
}
}
}
@@ -2705,10 +2758,20 @@ get_agmt_status(Slapi_PBlock *pb __attribute__((unused)),
agmt_get_changecount_string(ra, changecount_string, sizeof(changecount_string));
slapi_entry_add_string(e, "nsds5replicaChangesSentSinceStartup",
changecount_string);
if (ra->last_update_status[0] == '\0') {
+ char status_msg[STATUS_LEN];
+ char ts[SLAPI_TIMESTAMP_BUFSIZE];
+ time_t now;
+ time(&now);
+ strftime(ts, sizeof ts, "%FT%TZ", gmtime(&now));
slapi_entry_add_string(e, "nsds5replicaLastUpdateStatus",
"Error (0) No replication sessions started since
server startup");
+ PR_snprintf(status_msg, STATUS_LEN,
+ "{\"state\": \"green\",
\"ldap_rc\": \"0\", \"ldap_rc_text\": \"success\",
\"repl_rc\": \"0\", \"repl_rc_text\": \"replica
acquired\", "
+ "\"date\": \"%s\", \"message\":
\"Error (0) No replication sessions started since server startup\"}", ts);
+ slapi_entry_add_string(e, "nsds5replicaLastUpdateStatusJSON",
status_msg);
} else {
slapi_entry_add_string(e, "nsds5replicaLastUpdateStatus",
ra->last_update_status);
+ slapi_entry_add_string(e, "nsds5replicaLastUpdateStatusJSON",
ra->last_update_status_json);
}
slapi_entry_add_string(e, "nsds5replicaUpdateInProgress",
ra->update_in_progress ? "TRUE" : "FALSE");
@@ -2724,6 +2787,7 @@ get_agmt_status(Slapi_PBlock *pb __attribute__((unused)),
if (ra->last_init_status[0] != '\0') {
slapi_entry_add_string(e, "nsds5replicaLastInitStatus",
ra->last_init_status);
+ slapi_entry_add_string(e, "nsds5replicaLastInitStatusJSON",
ra->last_init_status_json);
}
}
bail:
diff --git a/ldap/servers/plugins/replication/repl5_protocol_util.c
b/ldap/servers/plugins/replication/repl5_protocol_util.c
index a48d4d0..bb9f9e7 100644
--- a/ldap/servers/plugins/replication/repl5_protocol_util.c
+++ b/ldap/servers/plugins/replication/repl5_protocol_util.c
@@ -374,13 +374,13 @@ acquire_replica(Private_Repl_Protocol *prp, char *prot_oid, RUV
**ruv)
"has the same Replica ID as this one. "
"Replication is aborting.\n",
agmt_get_long_name(prp->agmt));
- agmt_set_last_update_status(prp->agmt, 0, 0,
- "Unable to aquire replica: the
replica has the same "
+ agmt_set_last_update_status(prp->agmt, 0,
NSDS50_REPL_REPLICAID_ERROR,
+ "Unable to acquire replica: the
replica has the same "
"Replica ID as this one.
Replication is aborting.");
return_value = ACQUIRE_FATAL_ERROR;
break;
case NSDS50_REPL_BACKOFF:
- /* A replication sesssion hook on the replica
+ /* A replication session hook on the replica
* wants us to go into backoff mode. */
slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
"acquire_replica - "
@@ -487,9 +487,8 @@ acquire_replica(Private_Repl_Protocol *prp, char *prot_oid, RUV
**ruv)
"%s: Unable to obtain current CSN. "
"Replication is aborting.\n",
agmt_get_long_name(prp->agmt));
- agmt_set_last_update_status(prp->agmt, 0, 0,
- "Unable to obtain current CSN. "
- "Replication is aborting.");
+ agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_INTERNAL_ERROR,
+ "Unable to obtain current CSN. Replication
is aborting.");
return_value = ACQUIRE_FATAL_ERROR;
}
}
@@ -665,6 +664,8 @@ protocol_response2string(int response)
return "transient warning";
case NSDS50_REPL_RUV_ERROR:
return "RUV error";
+ case NSDS50_REPL_REPLICA_NO_RESPONSE:
+ return "no response received";
default:
return "unknown error";
}
--
To stop receiving notification emails like this one, please contact
the administrator of this repository.