From 74bdf05e12d1f91125916ad36f0b47487330438d Mon Sep 17 00:00:00 2001
From: Howard Chu <hyc@openldap.org>
Date: Wed, 9 Sep 2020 17:30:23 +0100
Subject: [PATCH] ITS#9043 tweak syncprov playlog logging

Don't log cookiecsn at top, it was already logged on receipt.
Only log the "srs csn" and "too old" message once for each sid.
Fix log output for empty UUID.
---
 servers/slapd/overlays/syncprov.c | 43 +++++++++++++++++++++----------
 1 file changed, 30 insertions(+), 13 deletions(-)

diff --git a/servers/slapd/overlays/syncprov.c b/servers/slapd/overlays/syncprov.c
index 1dbe665373..dbd3615076 100644
--- a/servers/slapd/overlays/syncprov.c
+++ b/servers/slapd/overlays/syncprov.c
@@ -1705,7 +1705,7 @@ syncprov_playlog( Operation *op, SlapReply *rs, sessionlog *sl,
 {
 	slap_overinst		*on = (slap_overinst *)op->o_bd->bd_info;
 	slog_entry *se;
-	int i, j, ndel, num, nmods, mmods;
+	int i, j, ndel, num, nmods, mmods, *sidchks;
 	char cbuf[LDAP_PVT_CSNSTR_BUFSIZE];
 	BerVarray uuids;
 	struct berval delcsn[2];
@@ -1721,6 +1721,7 @@ syncprov_playlog( Operation *op, SlapReply *rs, sessionlog *sl,
 	sl->sl_playing++;
 	ldap_pvt_thread_mutex_unlock( &sl->sl_mutex );
 
+	sidchks = op->o_tmpcalloc( srs->sr_state.numcsns + 1, sizeof(int), op->o_tmpmemctx );
 	uuids = op->o_tmpalloc( (num+1) * sizeof( struct berval ) +
 		num * UUID_LEN, op->o_tmpmemctx );
 	uuids[0].bv_val = (char *)(uuids + num + 1);
@@ -1733,31 +1734,45 @@ syncprov_playlog( Operation *op, SlapReply *rs, sessionlog *sl,
 	 * and everything else at the end. Do this first so we can
 	 * unlock the list mutex.
 	 */
-	Debug( LDAP_DEBUG_SYNC, "srs csn %s\n",
-		srs->sr_state.ctxcsn[0].bv_val, 0, 0 );
 	for ( se=sl->sl_head; se; se=se->se_next ) {
 		int k;
 
-		if ( LogTest( LDAP_DEBUG_SYNC ) ) {
-			char uuidstr[40];
-			lutil_uuidstr_from_normalized( se->se_uuid.bv_val, se->se_uuid.bv_len,
-				uuidstr, 40 );
-			Log4( LDAP_DEBUG_SYNC, ldap_syslog_level, "%s syncprov_playlog: "
-				"log entry tag=%lu uuid=%s cookie=%s\n",
-				op->o_log_prefix, se->se_tag, uuidstr, se->se_csn.bv_val );
-		}
 		ndel = 1;
 		for ( k=0; k<srs->sr_state.numcsns; k++ ) {
 			if ( se->se_sid == srs->sr_state.sids[k] ) {
 				ndel = ber_bvcmp( &se->se_csn, &srs->sr_state.ctxcsn[k] );
+				if ( !sidchks[k] || ndel > 0 ) {
+					if ( LogTest( LDAP_DEBUG_SYNC ) ) {
+						char uuidstr[40], *uuidp;
+						if ( se->se_uuid.bv_len ) {
+							lutil_uuidstr_from_normalized( se->se_uuid.bv_val, se->se_uuid.bv_len,
+								uuidstr, 40 );
+							uuidp = uuidstr;
+						} else {
+							uuidp = "";
+						}
+						if ( !sidchks[k] ) {
+							Log2( LDAP_DEBUG_SYNC, ldap_syslog_level, "%s syncprov_playlog: "
+								"srs csn %s\n",
+								op->o_log_prefix, srs->sr_state.ctxcsn[k].bv_val );
+						}
+						Log4( LDAP_DEBUG_SYNC, ldap_syslog_level, "%s syncprov_playlog: "
+							"log entry tag=%lu uuid=%s cookie=%s\n",
+							op->o_log_prefix, se->se_tag, uuidp, se->se_csn.bv_val );
+					}
+				}
 				break;
 			}
 		}
 		if ( ndel <= 0 ) {
-			Debug( LDAP_DEBUG_SYNC, "%s syncprov_playlog: "
-				"cmp %d, too old\n", op->o_log_prefix, ndel, 0 );
+			if ( !sidchks[k] ) {
+				Debug( LDAP_DEBUG_SYNC, "%s syncprov_playlog: "
+					"cmp %d, too old\n", op->o_log_prefix, ndel, 0 );
+				sidchks[k] = 1;
+			}
 			continue;
 		}
+		sidchks[k] = 1;
 		ndel = 0;
 		for ( k=0; k<numcsns; k++ ) {
 			if ( se->se_sid == sids[k] ) {
@@ -1800,6 +1815,8 @@ syncprov_playlog( Operation *op, SlapReply *rs, sessionlog *sl,
 	sl->sl_playing--;
 	ldap_pvt_thread_mutex_unlock( &sl->sl_mutex );
 
+	op->o_tmpfree( sidchks, op->o_tmpmemctx );
+
 	ndel = i;
 
 	/* Zero out unused slots */
-- 
2.47.2