Blob Blame History Raw
From 508a6dd02986024b03eeef62d135f7e16b0c85e9 Mon Sep 17 00:00:00 2001
From: Mark Reynolds <mreynolds@redhat.com>
Date: Thu, 2 Jun 2022 16:57:07 -0400
Subject: [PATCH 1/4] Issue 5329 - Improve replication extended op logging

Description:

We need logging around parsing extended op payload, right now when it
fails we have no idea why.

relates: https://github.com/389ds/389-ds-base/issues/5329

Reviewed by: progier, firstyear, and spichugi(Thanks!!!)
---
 ldap/servers/plugins/replication/repl_extop.c | 207 +++++++++++++++++-
 ldap/servers/slapd/slapi2runtime.c            |   1 -
 2 files changed, 197 insertions(+), 11 deletions(-)

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