Blame SOURCES/0013-Issue-5329-Improve-replication-extended-op-logging.patch

a77461
From 508a6dd02986024b03eeef62d135f7e16b0c85e9 Mon Sep 17 00:00:00 2001
a77461
From: Mark Reynolds <mreynolds@redhat.com>
a77461
Date: Thu, 2 Jun 2022 16:57:07 -0400
a77461
Subject: [PATCH 1/4] Issue 5329 - Improve replication extended op logging
a77461
a77461
Description:
a77461
a77461
We need logging around parsing extended op payload, right now when it
a77461
fails we have no idea why.
a77461
a77461
relates: https://github.com/389ds/389-ds-base/issues/5329
a77461
a77461
Reviewed by: progier, firstyear, and spichugi(Thanks!!!)
a77461
---
a77461
 ldap/servers/plugins/replication/repl_extop.c | 207 +++++++++++++++++-
a77461
 ldap/servers/slapd/slapi2runtime.c            |   1 -
a77461
 2 files changed, 197 insertions(+), 11 deletions(-)
a77461
a77461
diff --git a/ldap/servers/plugins/replication/repl_extop.c b/ldap/servers/plugins/replication/repl_extop.c
a77461
index 8b178610b..70c45ec50 100644
a77461
--- a/ldap/servers/plugins/replication/repl_extop.c
a77461
+++ b/ldap/servers/plugins/replication/repl_extop.c
a77461
@@ -73,6 +73,18 @@ done:
a77461
     return rc;
a77461
 }
a77461
 
a77461
+static void
a77461
+ruv_dump_to_log(const RUV *ruv, char *log_name)
a77461
+{
a77461
+    if (!ruv) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "%s: RUV: None\n", log_name);
a77461
+    } else {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "%s: RUV:\n", log_name);
a77461
+        ruv_dump(ruv, log_name, NULL);
a77461
+    }
a77461
+}
a77461
+
a77461
+
a77461
 /* The data_guid and data parameters should only be set if we
a77461
  * are talking with a 9.0 replica. */
a77461
 static struct berval *
a77461
@@ -95,33 +107,60 @@ create_ReplicationExtopPayload(const char *protocol_oid,
a77461
     PR_ASSERT(protocol_oid != NULL || send_end);
a77461
     PR_ASSERT(repl_root != NULL);
a77461
 
a77461
-    /* Create the request data */
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                "encoding '%s' payload...\n",
a77461
+                send_end ? "End Replication" : "Start Replication");
a77461
+    }
a77461
 
a77461
+    /* Create the request data */
a77461
     if ((tmp_bere = der_alloc()) == NULL) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                "encoding failed: der_alloc failed\n");
a77461
         rc = LDAP_ENCODING_ERROR;
a77461
         goto loser;
a77461
     }
a77461
     if (!send_end) {
a77461
         if (ber_printf(tmp_bere, "{ss", protocol_oid, repl_root) == -1) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                    "encoding failed: ber_printf failed - protocol_oid (%s) repl_root (%s)\n",
a77461
+                    protocol_oid, repl_root);
a77461
             rc = LDAP_ENCODING_ERROR;
a77461
             goto loser;
a77461
         }
a77461
+        if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                    "encoding protocol_oid: %s\n", protocol_oid);
a77461
+        }
a77461
     } else {
a77461
         if (ber_printf(tmp_bere, "{s", repl_root) == -1) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                    "encoding failed: ber_printf failed - repl_root (%s)\n",
a77461
+                    repl_root);
a77461
             rc = LDAP_ENCODING_ERROR;
a77461
             goto loser;
a77461
         }
a77461
+        if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                    "encoding repl_root: %s\n", repl_root);
a77461
+        }
a77461
     }
a77461
 
a77461
     sdn = slapi_sdn_new_dn_byref(repl_root);
a77461
     repl = replica_get_replica_from_dn(sdn);
a77461
     if (repl == NULL) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                "encoding failed: failed to get replica from dn (%s)\n",
a77461
+                slapi_sdn_get_dn(sdn));
a77461
         rc = LDAP_OPERATIONS_ERROR;
a77461
         goto loser;
a77461
     }
a77461
 
a77461
     ruv_obj = replica_get_ruv(repl);
a77461
     if (ruv_obj == NULL) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                "encoding failed: failed to get ruv from replica suffix (%s)\n",
a77461
+                slapi_sdn_get_dn(sdn));
a77461
         rc = LDAP_OPERATIONS_ERROR;
a77461
         goto loser;
a77461
     }
a77461
@@ -134,8 +173,14 @@ create_ReplicationExtopPayload(const char *protocol_oid,
a77461
     /* We need to encode and send each time the local ruv in case we have changed it */
a77461
     rc = encode_ruv(tmp_bere, ruv);
a77461
     if (rc != 0) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                "encoding failed: encode_ruv failed for replica suffix (%s)\n",
a77461
+                slapi_sdn_get_dn(sdn));
a77461
         goto loser;
a77461
     }
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        ruv_dump_to_log(ruv, "create_ReplicationExtopPayload");
a77461
+    }
a77461
 
a77461
     if (!send_end) {
a77461
         char s[CSN_STRSIZE];
a77461
@@ -157,36 +202,67 @@ create_ReplicationExtopPayload(const char *protocol_oid,
a77461
         charray_merge(&referrals_to_send, local_replica_referral, 0);
a77461
         if (NULL != referrals_to_send) {
a77461
             if (ber_printf(tmp_bere, "[v]", referrals_to_send) == -1) {
a77461
+                slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                        "encoding failed: ber_printf (referrals_to_send)\n");
a77461
                 rc = LDAP_ENCODING_ERROR;
a77461
                 goto loser;
a77461
             }
a77461
+            if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+                for (size_t i = 0; referrals_to_send[i]; i++) {
a77461
+                    slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                            "encoding ref: %s\n", referrals_to_send[i]);
a77461
+                }
a77461
+            }
a77461
             slapi_ch_free((void **)&referrals_to_send);
a77461
         }
a77461
         /* Add the CSN */
a77461
         PR_ASSERT(NULL != csn);
a77461
         if (ber_printf(tmp_bere, "s", csn_as_string(csn, PR_FALSE, s)) == -1) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                    "encoding failed: ber_printf (csnstr)\n");
a77461
             rc = LDAP_ENCODING_ERROR;
a77461
             goto loser;
a77461
         }
a77461
+        if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                    "encoding csn: %s\n", csn_as_string(csn, PR_FALSE, s));
a77461
+        }
a77461
     }
a77461
 
a77461
     /* If we have data to send to a 9.0 style replica, set it here. */
a77461
     if (data_guid && data) {
a77461
         if (ber_printf(tmp_bere, "sO", data_guid, data) == -1) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                    "encoding failed: ber_printf (data_guid, data)\n");
a77461
             rc = LDAP_ENCODING_ERROR;
a77461
             goto loser;
a77461
         }
a77461
+        if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                    "encoding data_guid (%s) data (%s:%ld)\n",
a77461
+                    data_guid, data->bv_val, data->bv_len);
a77461
+        }
a77461
     }
a77461
 
a77461
+
a77461
     if (ber_printf(tmp_bere, "}") == -1) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                "encoding failed: ber_printf\n");
a77461
         rc = LDAP_ENCODING_ERROR;
a77461
         goto loser;
a77461
     }
a77461
 
a77461
     if (ber_flatten(tmp_bere, &req_data) == -1) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "create_ReplicationExtopPayload",
a77461
+                "encoding failed: ber_flatten failed\n");
a77461
         rc = LDAP_LOCAL_ERROR;
a77461
         goto loser;
a77461
     }
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "create_ReplicationExtopPayload - "
a77461
+                "Encoding finished\n");
a77461
+    }
a77461
+
a77461
     /* Success */
a77461
     goto done;
a77461
 
a77461
@@ -293,8 +369,14 @@ decode_startrepl_extop(Slapi_PBlock *pb, char **protocol_oid, char **repl_root,
a77461
     if ((NULL == extop_oid) ||
a77461
         ((strcmp(extop_oid, REPL_START_NSDS50_REPLICATION_REQUEST_OID) != 0) &&
a77461
          (strcmp(extop_oid, REPL_START_NSDS90_REPLICATION_REQUEST_OID) != 0)) ||
a77461
-        !BV_HAS_DATA(extop_value)) {
a77461
+        !BV_HAS_DATA(extop_value))
a77461
+    {
a77461
         /* bogus */
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: extop_oid (%s) (%s) extop_value (%s)\n",
a77461
+                NULL == extop_oid ? "NULL" : "Ok",
a77461
+                extop_oid ? extop_oid : "",
a77461
+                extop_value ? !BV_HAS_DATA(extop_value) ? "No data" : "Ok" : "No data");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
@@ -307,25 +389,36 @@ decode_startrepl_extop(Slapi_PBlock *pb, char **protocol_oid, char **repl_root,
a77461
     }
a77461
 
a77461
     if ((tmp_bere = ber_init(extop_value)) == NULL) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: ber_init for extop_value (%s:%lu)\n",
a77461
+                extop_value->bv_val, extop_value->bv_len);
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     if (ber_scanf(tmp_bere, "{") == LBER_ERROR) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: ber_scanf 1\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     /* Get the required protocol OID and root of replicated subtree */
a77461
     if (ber_get_stringa(tmp_bere, protocol_oid) == LBER_DEFAULT) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: ber_get_stringa (protocol_oid)\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     if (ber_get_stringa(tmp_bere, repl_root) == LBER_DEFAULT) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: ber_get_stringa (repl_root)\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
 
a77461
     /* get supplier's ruv */
a77461
     if (decode_ruv(tmp_bere, supplier_ruv) == -1) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: decode_ruv (supplier_ruv)\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
@@ -333,33 +426,45 @@ decode_startrepl_extop(Slapi_PBlock *pb, char **protocol_oid, char **repl_root,
a77461
     /* Get the optional set of referral URLs */
a77461
     if (ber_peek_tag(tmp_bere, &len) == LBER_SET) {
a77461
         if (ber_scanf(tmp_bere, "[v]", extra_referrals) == LBER_ERROR) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                    "decoding failed: ber_scanf (extra_referrals)\n");
a77461
             rc = -1;
a77461
             goto free_and_return;
a77461
         }
a77461
     }
a77461
     /* Get the CSN */
a77461
     if (ber_get_stringa(tmp_bere, csnstr) == LBER_ERROR) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: ber_get_stringa (csnstr)\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     /* Get the optional replication session callback data. */
a77461
     if (ber_peek_tag(tmp_bere, &len) == LBER_OCTETSTRING) {
a77461
         if (ber_get_stringa(tmp_bere, data_guid) == LBER_ERROR) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                    "decoding failed: ber_get_stringa (data_guid)\n");
a77461
             rc = -1;
a77461
             goto free_and_return;
a77461
         }
a77461
         /* If a data_guid was specified, data must be specified as well. */
a77461
         if (ber_peek_tag(tmp_bere, &len) == LBER_OCTETSTRING) {
a77461
             if (ber_get_stringal(tmp_bere, data) == LBER_ERROR) {
a77461
+                slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                        "decoding failed: ber_get_stringal (data)\n");
a77461
                 rc = -1;
a77461
                 goto free_and_return;
a77461
             }
a77461
         } else {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                    "decoding failed: ber_peek_tag\n");
a77461
             rc = -1;
a77461
             goto free_and_return;
a77461
         }
a77461
     }
a77461
     if (ber_scanf(tmp_bere, "}") == LBER_ERROR) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_startrepl_extop",
a77461
+                "decoding failed: ber_scanf 2\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
@@ -378,6 +483,22 @@ free_and_return:
a77461
         if (*supplier_ruv) {
a77461
             ruv_destroy(supplier_ruv);
a77461
         }
a77461
+    } else if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "decode_startrepl_extop - decoding payload...\n");
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "decode_startrepl_extop - decoded protocol_oid: %s\n", *protocol_oid);
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "decode_startrepl_extop - decoded repl_root: %s\n", *repl_root);
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "decode_startrepl_extop - decoded csn: %s\n", *csnstr);
a77461
+        ruv_dump_to_log(*supplier_ruv, "decode_startrepl_extop");
a77461
+        for (size_t i = 0; *extra_referrals && *extra_referrals[i]; i++) {
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "decode_startrepl_extop - "
a77461
+                "decoded referral: %s\n", *extra_referrals[i]);
a77461
+        }
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "decode_startrepl_extop - Finshed decoding payload.\n");
a77461
     }
a77461
     if (NULL != tmp_bere) {
a77461
         ber_free(tmp_bere, 1);
a77461
@@ -406,30 +527,54 @@ decode_endrepl_extop(Slapi_PBlock *pb, char **repl_root)
a77461
 
a77461
     if ((NULL == extop_oid) ||
a77461
         (strcmp(extop_oid, REPL_END_NSDS50_REPLICATION_REQUEST_OID) != 0) ||
a77461
-        !BV_HAS_DATA(extop_value)) {
a77461
+        !BV_HAS_DATA(extop_value))
a77461
+    {
a77461
         /* bogus */
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_endrepl_extop",
a77461
+                "decoding failed: extop_oid (%s) correct oid (%s) extop_value data (%s)\n",
a77461
+                extop_oid ? extop_oid : "NULL",
a77461
+                extop_oid ? strcmp(extop_oid, REPL_END_NSDS50_REPLICATION_REQUEST_OID) != 0 ? "wrong oid" : "correct oid" : "NULL",
a77461
+                !BV_HAS_DATA(extop_value) ? "No data" : "Has data");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
 
a77461
     if ((tmp_bere = ber_init(extop_value)) == NULL) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_endrepl_extop",
a77461
+                "decoding failed: ber_init failed:  extop_value (%s:%lu)\n",
a77461
+                extop_value->bv_val, extop_value->bv_len);
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     if (ber_scanf(tmp_bere, "{") == LBER_DEFAULT) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_endrepl_extop",
a77461
+                "decoding failed: ber_scanf failed1\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     /* Get the required root of replicated subtree */
a77461
     if (ber_get_stringa(tmp_bere, repl_root) == LBER_DEFAULT) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_endrepl_extop",
a77461
+                "decoding failed: ber_get_stringa failed\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
     if (ber_scanf(tmp_bere, "}") == LBER_DEFAULT) {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_endrepl_extop",
a77461
+                "decoding failed: ber_scanf2 failed\n");
a77461
         rc = -1;
a77461
         goto free_and_return;
a77461
     }
a77461
 
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, "decode_endrepl_extop",
a77461
+                "Decoding payload...\n");
a77461
+        slapi_log_err(SLAPI_LOG_REPL, "decode_endrepl_extop",
a77461
+                "Decoded repl_root: %s\n", *repl_root);
a77461
+        slapi_log_err(SLAPI_LOG_REPL, "decode_endrepl_extop",
a77461
+                "Finished decoding payload.\n");
a77461
+    }
a77461
+
a77461
 free_and_return:
a77461
     if (NULL != tmp_bere) {
a77461
         ber_free(tmp_bere, 1);
a77461
@@ -461,27 +606,46 @@ decode_repl_ext_response(struct berval *bvdata, int *response_code, struct berva
a77461
     PR_ASSERT(NULL != ruv_bervals);
a77461
 
a77461
     if ((NULL == response_code) || (NULL == ruv_bervals) ||
a77461
-        (NULL == data_guid) || (NULL == data) || !BV_HAS_DATA(bvdata)) {
a77461
+        (NULL == data_guid) || (NULL == data) || !BV_HAS_DATA(bvdata))
a77461
+    {
a77461
+        slapi_log_err(SLAPI_LOG_ERR, "decode_repl_ext_response",
a77461
+                "decoding failed: response_code (%s) ruv_bervals (%s) data_guid (%s) data (%s) bvdata (%s)\n",
a77461
+                NULL == response_code ? "NULL" : "Ok",
a77461
+                NULL == ruv_bervals ? "NULL" : "Ok",
a77461
+                NULL == data_guid ? "NULL" : "Ok",
a77461
+                NULL == data ? "NULL" : "Ok",
a77461
+               !BV_HAS_DATA(bvdata) ? "No data" : "Ok");
a77461
         return_value = -1;
a77461
     } else {
a77461
         ber_len_t len;
a77461
         ber_int_t temp_response_code = 0;
a77461
         *ruv_bervals = NULL;
a77461
         if ((tmp_bere = ber_init(bvdata)) == NULL) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "decode_repl_ext_response",
a77461
+                    "decoding failed: ber_init failed from bvdata (%s:%lu)\n",
a77461
+                    bvdata->bv_val, bvdata->bv_len);
a77461
             return_value = -1;
a77461
         } else if (ber_scanf(tmp_bere, "{e", &temp_response_code) == LBER_ERROR) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "decode_repl_ext_response",
a77461
+                    "decoding failed: ber_scanf failed\n");
a77461
             return_value = -1;
a77461
         } else if (ber_peek_tag(tmp_bere, &len) == LBER_SEQUENCE) {
a77461
             if (ber_scanf(tmp_bere, "{V}", ruv_bervals) == LBER_ERROR) {
a77461
+                slapi_log_err(SLAPI_LOG_ERR, "decode_repl_ext_response",
a77461
+                     "decoding failed: ber_scanf2 failed from ruv_bervals\n");
a77461
                 return_value = -1;
a77461
             }
a77461
         }
a77461
         /* Check for optional data from replication session callback */
a77461
         if (ber_peek_tag(tmp_bere, &len) == LBER_OCTETSTRING) {
a77461
             if (ber_scanf(tmp_bere, "aO}", data_guid, data) == LBER_ERROR) {
a77461
+                slapi_log_err(SLAPI_LOG_ERR, "decode_repl_ext_response",
a77461
+                        "decoding failed: ber_scanf3 failed from data_guid & data\n");
a77461
                 return_value = -1;
a77461
             }
a77461
         } else if (ber_scanf(tmp_bere, "}") == LBER_ERROR) {
a77461
+            slapi_log_err(SLAPI_LOG_ERR, "decode_repl_ext_response",
a77461
+                    "decoding failed: ber_scanf4 failed\n");
a77461
             return_value = -1;
a77461
         }
a77461
 
a77461
@@ -934,17 +1098,36 @@ send_response:
a77461
         /* ONREPL - not sure what we suppose to do here */
a77461
     }
a77461
     ber_printf(resp_bere, "{e", response);
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "multisupplier_extop_StartNSDS50ReplicationRequest - encoded response: %d\n",
a77461
+                response);
a77461
+    }
a77461
     if (NULL != ruv_bervals) {
a77461
         ber_printf(resp_bere, "{V}", ruv_bervals);
a77461
+        if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+            ruv_dump_to_log(ruv, "multisupplier_extop_StartNSDS50ReplicationRequest");
a77461
+        }
a77461
     }
a77461
+
a77461
     /* Add extra data from replication session callback if necessary */
a77461
     if (is90 && data_guid && data) {
a77461
         ber_printf(resp_bere, "sO", data_guid, data);
a77461
+        if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                    "multisupplier_extop_StartNSDS50ReplicationRequest - encoded data_guid (%s) data (%s:%ld)\n",
a77461
+                    data_guid, data->bv_val, data->bv_len);
a77461
+        }
a77461
     }
a77461
 
a77461
     ber_printf(resp_bere, "}");
a77461
     ber_flatten(resp_bere, &resp_bval);
a77461
 
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
a77461
+                "multisupplier_extop_StartNSDS50ReplicationRequest - Finished encoding payload\n");
a77461
+    }
a77461
+
a77461
     if (is90) {
a77461
         slapi_pblock_set(pb, SLAPI_EXT_OP_RET_OID, REPL_NSDS90_REPLICATION_RESPONSE_OID);
a77461
     } else {
a77461
@@ -1005,8 +1188,8 @@ send_response:
a77461
              * sending this request).
a77461
              * The situation is confused
a77461
              */
a77461
-            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "multimaster_extop_StartNSDS50ReplicationRequest - "
a77461
-                                                            "already acquired replica: replica not ready (%d) (replica=%s)\n",
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "multisupplier_extop_StartNSDS50ReplicationRequest - "
a77461
+                          "already acquired replica: replica not ready (%d) (replica=%s)\n",
a77461
                           response, replica_get_name(r) ? replica_get_name(r) : "no name");
a77461
 
a77461
             /*
a77461
@@ -1016,8 +1199,8 @@ send_response:
a77461
             if (r) {
a77461
 
a77461
                 r_locking_conn = replica_get_locking_conn(r);
a77461
-                slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "multimaster_extop_StartNSDS50ReplicationRequest - "
a77461
-                                                                "already acquired replica: locking_conn=%" PRIu64 ", current connid=%" PRIu64 "\n",
a77461
+                slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "multisupplier_extop_StartNSDS50ReplicationRequest - "
a77461
+                              "already acquired replica: locking_conn=%" PRIu64 ", current connid=%" PRIu64 "\n",
a77461
                               r_locking_conn, connid);
a77461
 
a77461
                 if ((r_locking_conn != ULONG_MAX) && (r_locking_conn == connid)) {
a77461
@@ -1032,8 +1215,8 @@ send_response:
a77461
              * On the supplier, we need to close the connection so
a77461
              * that the RA will restart a new session in a clear state
a77461
              */
a77461
-            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "multimaster_extop_StartNSDS50ReplicationRequest - "
a77461
-                                                            "already acquired replica: disconnect conn=%" PRIu64 "\n",
a77461
+            slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "multisupplier_extop_StartNSDS50ReplicationRequest - "
a77461
+                           "already acquired replica: disconnect conn=%" PRIu64 "\n",
a77461
                           connid);
a77461
             slapi_disconnect_server(conn);
a77461
         }
a77461
@@ -1210,6 +1393,10 @@ send_response:
a77461
     if ((resp_bere = der_alloc()) == NULL) {
a77461
         goto free_and_return;
a77461
     }
a77461
+    if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
a77461
+        slapi_log_err(SLAPI_LOG_REPL, "multisupplier_extop_EndNSDS50ReplicationRequest",
a77461
+                "encoded response: %d\n", response);
a77461
+    }
a77461
     ber_printf(resp_bere, "{e}", response);
a77461
     ber_flatten(resp_bere, &resp_bval);
a77461
     slapi_pblock_set(pb, SLAPI_EXT_OP_RET_OID, REPL_NSDS50_REPLICATION_RESPONSE_OID);
a77461
diff --git a/ldap/servers/slapd/slapi2runtime.c b/ldap/servers/slapd/slapi2runtime.c
a77461
index 53927934a..e622f1b65 100644
a77461
--- a/ldap/servers/slapd/slapi2runtime.c
a77461
+++ b/ldap/servers/slapd/slapi2runtime.c
a77461
@@ -88,7 +88,6 @@ slapi_lock_mutex(Slapi_Mutex *mutex)
a77461
 inline int __attribute__((always_inline))
a77461
 slapi_unlock_mutex(Slapi_Mutex *mutex)
a77461
 {
a77461
-    PR_ASSERT(mutex != NULL);
a77461
     if (mutex == NULL || pthread_mutex_unlock((pthread_mutex_t *)mutex) != 0) {
a77461
         return (0);
a77461
     } else {
a77461
-- 
a77461
2.37.1
a77461