X-Git-Url: https://git.sur5r.net/?a=blobdiff_plain;f=servers%2Fslapd%2Foverlays%2Faccesslog.c;h=53369b32c54c1553f92419319907783450d49e54;hb=4a574324fd8c35c9ceffecd149bb14ab84b59a85;hp=0e3d8d88ca6a19b4f615d6ea1ef88081c1807bff;hpb=eb5faf59284a79c1496535e05ac8385f906e2f06;p=openldap

diff --git a/servers/slapd/overlays/accesslog.c b/servers/slapd/overlays/accesslog.c
index 0e3d8d88ca..53369b32c5 100644
--- a/servers/slapd/overlays/accesslog.c
+++ b/servers/slapd/overlays/accesslog.c
@@ -2,7 +2,7 @@
 /* $OpenLDAP$ */
 /* This work is part of OpenLDAP Software <http://www.openldap.org/>.
  *
- * Copyright 2005-2014 The OpenLDAP Foundation.
+ * Copyright 2005-2017 The OpenLDAP Foundation.
  * Portions copyright 2004-2005 Symas Corporation.
  * All rights reserved.
  *
@@ -578,7 +578,7 @@ log_age_unparse( int age, struct berval *agebv, size_t size )
 	agebv->bv_len = ptr - agebv->bv_val;
 }
 
-static slap_callback nullsc = { NULL, NULL, NULL, NULL };
+static slap_callback nullsc;
 
 #define PURGE_INCREMENT	100
 
@@ -637,7 +637,7 @@ accesslog_purge( void *ctx, void *arg )
 	OperationBuffer opbuf;
 	Operation *op;
 	SlapReply rs = {REP_RESULT};
-	slap_callback cb = { NULL, log_old_lookup, NULL, NULL };
+	slap_callback cb = { NULL, log_old_lookup, NULL, NULL, NULL };
 	Filter f;
 	AttributeAssertion ava = ATTRIBUTEASSERTION_INIT;
 	purge_data pd = {0};
@@ -701,6 +701,7 @@ accesslog_purge( void *ctx, void *arg )
 			}
 			ch_free( pd.ndn[i].bv_val );
 			ch_free( pd.dn[i].bv_val );
+			ldap_pvt_thread_pool_pausecheck( &connection_pool );
 		}
 		ch_free( pd.ndn );
 		ch_free( pd.dn );
@@ -1490,9 +1491,17 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 	if ( lo->mask & LOG_OP_WRITES ) {
 		slap_callback *cb;
 
-		/* These internal ops are not logged */
-		if ( op->o_dont_replicate && op->orm_no_opattrs )
+		/* Most internal ops are not logged */
+		if ( op->o_dont_replicate) {
+			/* Let contextCSN updates from syncrepl thru; the underlying
+			 * syncprov needs to see them. Skip others.
+			 */
+			if (( op->o_tag != LDAP_REQ_MODIFY ||
+				op->orm_modlist->sml_op != LDAP_MOD_REPLACE ||
+				op->orm_modlist->sml_desc != slap_schema.si_ad_contextCSN ) &&
+				op->orm_no_opattrs )
 			return SLAP_CB_CONTINUE;
+		}
 
 		ldap_pvt_thread_mutex_lock( &li->li_log_mutex );
 		old = li->li_old;
@@ -1506,9 +1515,19 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 				break;
 			}
 		}
+#ifdef RMUTEX_DEBUG
+		Debug( LDAP_DEBUG_SYNC,
+			"accesslog_response: unlocking rmutex for tid %x\n",
+			op->o_tid, 0, 0 );
+#endif
 		ldap_pvt_thread_rmutex_unlock( &li->li_op_rmutex, op->o_tid );
 	}
 
+	/* ignore these internal reads */
+	if (( lo->mask & LOG_OP_READS ) && op->o_do_not_cache ) {
+		return SLAP_CB_CONTINUE;
+	}
+
 	if ( li->li_success && rs->sr_err != LDAP_SUCCESS )
 		goto done;
 
@@ -1518,7 +1537,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 
 	if ( rs->sr_text ) {
 		ber_str2bv( rs->sr_text, 0, 0, &bv );
-		attr_merge_one( e, ad_reqMessage, &bv, NULL );
+		attr_merge_normalize_one( e, ad_reqMessage, &bv, op->o_tmpmemctx );
 	}
 	bv.bv_len = snprintf( timebuf, sizeof( timebuf ), "%d", rs->sr_err );
 	if ( bv.bv_len < sizeof( timebuf ) ) {
@@ -1572,7 +1591,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 
 	case LOG_EN_MODRDN:
 	case LOG_EN_MODIFY:
-		/* count all the mods */
+		/* count all the mods + attributes (ITS#6545) */
 		i = 0;
 		for ( m = op->orm_modlist; m; m = m->sml_next ) {
 			if ( m->sml_values ) {
@@ -1582,6 +1601,9 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 			{
 				i++;
 			}
+			if ( m->sml_next && m->sml_desc == m->sml_next->sml_desc ) {
+				i++;
+			}
 		}
 		vals = ch_malloc( (i+1) * sizeof( struct berval ));
 		i = 0;
@@ -1652,6 +1674,12 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 				*ptr = '\0';
 				i++;
 			}
+			/* ITS#6545: when the same attribute is edited multiple times,
+			 * record the transition */
+			if ( m->sml_next && m->sml_desc == m->sml_next->sml_desc ) {
+				ber_str2bv( ":", STRLENOF(":"), 1, &vals[i] );
+				i++;
+			}
 		}
 
 		if ( i > 0 ) {
@@ -1727,7 +1755,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 			(struct berval *)&slap_true_bv : (struct berval *)&slap_false_bv,
 			NULL );
 		if ( !BER_BVISEMPTY( &op->ors_filterstr ))
-			attr_merge_one( e, ad_reqFilter, &op->ors_filterstr, NULL );
+			attr_merge_normalize_one( e, ad_reqFilter, &op->ors_filterstr, op->o_tmpmemctx );
 		if ( op->ors_attrs ) {
 			int j;
 			/* count them */
@@ -1742,7 +1770,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 				}
 			}
 			BER_BVZERO(&vals[j]);
-			attr_merge( e, ad_reqAttr, vals, NULL );
+			attr_merge_normalize( e, ad_reqAttr, vals, op->o_tmpmemctx );
 			op->o_tmpfree( vals, op->o_tmpmemctx );
 		}
 		bv.bv_val = timebuf;
@@ -1769,7 +1797,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 			attr_merge_one( e, ad_reqVersion, &bv, NULL );
 		} /* else? */
 		if ( op->orb_method == LDAP_AUTH_SIMPLE ) {
-			attr_merge_one( e, ad_reqMethod, &simple, NULL );
+			attr_merge_normalize_one( e, ad_reqMethod, &simple, op->o_tmpmemctx );
 		} else {
 			bv.bv_len = STRLENOF("SASL()") + op->orb_mech.bv_len;
 			bv.bv_val = op->o_tmpalloc( bv.bv_len + 1, op->o_tmpmemctx );
@@ -1777,7 +1805,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 			ptr = lutil_strcopy( ptr, op->orb_mech.bv_val );
 			*ptr++ = ')';
 			*ptr = '\0';
-			attr_merge_one( e, ad_reqMethod, &bv, NULL );
+			attr_merge_normalize_one( e, ad_reqMethod, &bv, op->o_tmpmemctx );
 			op->o_tmpfree( bv.bv_val, op->o_tmpmemctx );
 		}
 
@@ -1826,10 +1854,29 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 	op2.o_req_ndn = e->e_nname;
 	op2.ora_e = e;
 	op2.o_callback = &nullsc;
+	op2.o_csn = op->o_csn;
+	/* contextCSN updates may still reach here */
+	op2.o_dont_replicate = op->o_dont_replicate;
 
 	if (( lo->mask & LOG_OP_WRITES ) && !BER_BVISEMPTY( &op->o_csn )) {
-		slap_queue_csn( &op2, &op->o_csn );
-		do_graduate = 1;
+		struct berval maxcsn;
+		char cbuf[LDAP_PVT_CSNSTR_BUFSIZE];
+		int foundit;
+		cbuf[0] = '\0';
+		maxcsn.bv_val = cbuf;
+		maxcsn.bv_len = sizeof(cbuf);
+		/* If there was a commit CSN on the main DB,
+		 * we must propagate it to the log DB for its
+		 * own syncprov. Otherwise, don't generate one.
+		 */
+		slap_get_commit_csn( op, &maxcsn, &foundit );
+		if ( !BER_BVISEMPTY( &maxcsn ) ) {
+			slap_queue_csn( &op2, &op->o_csn );
+			do_graduate = 1;
+		} else {
+			attr_merge_normalize_one( e, slap_schema.si_ad_entryCSN,
+				&op->o_csn, op->o_tmpmemctx );
+		}
 	}
 
 	op2.o_bd->be_add( &op2, &rs2 );
@@ -1837,8 +1884,6 @@ static int accesslog_response(Operation *op, SlapReply *rs) {
 	e = NULL;
 	if ( do_graduate ) {
 		slap_graduate_commit_csn( &op2 );
-		if ( op2.o_csn.bv_val )
-			op->o_tmpfree( op2.o_csn.bv_val, op->o_tmpmemctx );
 	}
 
 done:
@@ -1917,8 +1962,22 @@ accesslog_op_mod( Operation *op, SlapReply *rs )
 	int doit = 0;
 
 	/* These internal ops are not logged */
-	if ( op->o_dont_replicate && op->orm_no_opattrs )
+	if ( op->o_dont_replicate ) {
+		/* Let contextCSN updates from syncrepl thru; the underlying
+		 * syncprov needs to see them. Skip others.
+		 */
+		if (( op->o_tag != LDAP_REQ_MODIFY ||
+			op->orm_modlist->sml_op != LDAP_MOD_REPLACE ||
+			op->orm_modlist->sml_desc != slap_schema.si_ad_contextCSN ) &&
+			op->orm_no_opattrs )
 		return SLAP_CB_CONTINUE;
+		/* give this a unique timestamp */
+		op->o_tincr++;
+		if ( op->o_tincr >= 1000000 ) {
+			op->o_tincr -= 1000000;
+			op->o_time++;
+		}
+	}
 
 	logop = accesslog_op2logop( op );
 	lo = logops+logop+EN_OFFSET;
@@ -1935,15 +1994,23 @@ accesslog_op_mod( Operation *op, SlapReply *rs )
 	}
 			
 	if ( doit ) {
-		slap_callback *cb = op->o_tmpalloc( sizeof( slap_callback ), op->o_tmpmemctx ), *cb2;
+		slap_callback *cb = op->o_tmpcalloc( 1, sizeof( slap_callback ), op->o_tmpmemctx ), *cb2;
 		cb->sc_cleanup = accesslog_mod_cleanup;
-		cb->sc_response = NULL;
 		cb->sc_private = on;
-		cb->sc_next = NULL;
 		for ( cb2 = op->o_callback; cb2->sc_next; cb2 = cb2->sc_next );
 		cb2->sc_next = cb;
 
+#ifdef RMUTEX_DEBUG
+		Debug( LDAP_DEBUG_SYNC,
+			"accesslog_op_mod: locking rmutex for tid %x\n",
+			op->o_tid, 0, 0 );
+#endif
 		ldap_pvt_thread_rmutex_lock( &li->li_op_rmutex, op->o_tid );
+#ifdef RMUTEX_DEBUG
+		Debug( LDAP_DEBUG_STATS,
+			"accesslog_op_mod: locked rmutex for tid %x\n",
+			op->o_tid, 0, 0 );
+#endif
 		if ( li->li_oldf && ( op->o_tag == LDAP_REQ_DELETE ||
 			op->o_tag == LDAP_REQ_MODIFY ||
 			( op->o_tag == LDAP_REQ_MODRDN && li->li_oldattrs )))