From 43ebfa8fb4249642506b0b902c241c8b263867e8 Mon Sep 17 00:00:00 2001 From: =?utf8?q?Ond=C5=99ej=20Kuzn=C3=ADk?= Date: Tue, 9 Oct 2018 13:00:49 +0200 Subject: [PATCH] ITS#6467 Make accesslog a possible sessionlog source --- doc/man/man5/slapo-syncprov.5 | 8 + servers/slapd/overlays/syncprov.c | 411 +++++++++++++++++++++++++++++- 2 files changed, 417 insertions(+), 2 deletions(-) diff --git a/doc/man/man5/slapo-syncprov.5 b/doc/man/man5/slapo-syncprov.5 index 303401b136..0111fca9e1 100644 --- a/doc/man/man5/slapo-syncprov.5 +++ b/doc/man/man5/slapo-syncprov.5 @@ -49,6 +49,14 @@ operations (except Adds) are recorded in the log. When using the session log, it is helpful to set an eq index on the entryUUID attribute in the underlying database. .TP +.B syncprov\-sessionlog\-source +Should not be set when syncprov-sessionlog is set and vice versa. + +When accesslog for this database is configured and is logging at this suffix, +it can be used as the session log source instead of the in-memory session log +mentioned above. This log has the advantage of not starting afresh every time +the server is restarted. +.TP .B syncprov\-nopresent TRUE | FALSE Specify that the Present phase of refreshing should be skipped. This value should only be set TRUE for a syncprov instance on top of a log database diff --git a/servers/slapd/overlays/syncprov.c b/servers/slapd/overlays/syncprov.c index 5a7f6cbae4..a9bef818f9 100644 --- a/servers/slapd/overlays/syncprov.c +++ b/servers/slapd/overlays/syncprov.c @@ -137,10 +137,24 @@ typedef struct sessionlog { ldap_pvt_thread_mutex_t sl_mutex; } sessionlog; +/* Accesslog callback data */ +typedef struct syncprov_accesslog_deletes { + Operation *op; + SlapReply *rs; + sync_control *srs; + BerVarray ctxcsn; + int numcsns, *sids; + Avlnode *uuids; + BerVarray uuid_list; + int ndel, list_len; + char *uuid_buf; +} syncprov_accesslog_deletes; + /* The main state for this overlay */ typedef struct syncprov_info_t { syncops *si_ops; struct berval si_contextdn; + struct berval si_logbase; BerVarray si_ctxcsn; /* ldapsync context */ int *si_sids; int si_numcsns; @@ -186,6 +200,9 @@ typedef struct fbase_cookie { static AttributeName csn_anlist[3]; static AttributeName uuid_anlist[2]; +static AttributeDescription *ad_reqType, *ad_reqResult, *ad_reqDN, + *ad_reqEntryUUID, *ad_minCSN; + /* Build a LDAPsync intermediate state control */ static int syncprov_state_ctrl( @@ -403,6 +420,14 @@ sp_avl_cmp( const void *c1, const void *c2 ) return ber_bvcmp( &m1->mt_dn, &m2->mt_dn ); } +static int +sp_uuid_cmp( const void *l, const void *r ) +{ + const struct berval *left = l, *right = r; + + return ber_bvcmp( left, right ); +} + /* syncprov_findbase: * finds the true DN of the base of a search (with alias dereferencing) and * checks to make sure the base entry doesn't get replaced with a different @@ -1777,6 +1802,149 @@ check_uuidlist_presence( return mods; } +/* + * On each entry we get from the DB: + * - if it's an ADD, skip + * - check we've not handled it yet, skip if we have + * - check if it's a DELETE or missing from the DB now + * - send a new syncinfo entry + * - remember we've handled it already + * + * If we exhaust the list, clear it, forgetting entries we've handled so far. + */ +static int +syncprov_accesslog_uuid_cb( Operation *op, SlapReply *rs ) +{ + slap_callback *sc = op->o_callback; + syncprov_accesslog_deletes *uuid_progress = sc->sc_private; + Attribute *a, *attrs; + sync_control *srs = uuid_progress->srs; + struct berval *bv, csn[2] = {}, uuid[2] = {}, + add = BER_BVC("add"), + delete = BER_BVC("delete"); + int cmp, sid, i, is_delete = 0, rc; + + if ( rs->sr_type != REP_SEARCH ) { + return rs->sr_err; + } + attrs = rs->sr_entry->e_attrs; + + a = attr_find( attrs, ad_reqType ); + if ( !a || a->a_numvals == 0 ) { + rs->sr_err = LDAP_CONSTRAINT_VIOLATION; + return rs->sr_err; + } + + if ( bvmatch( &a->a_nvals[0], &add ) ) { + return rs->sr_err; + } + + if ( bvmatch( &a->a_nvals[0], &delete ) ) { + is_delete = 1; + } + + /* + * Only pick entries that are both: + */ + a = attr_find( attrs, slap_schema.si_ad_entryCSN ); + if ( !a || a->a_numvals == 0 ) { + rs->sr_err = LDAP_CONSTRAINT_VIOLATION; + return rs->sr_err; + } + csn[0] = a->a_nvals[0]; + + sid = slap_parse_csn_sid( &csn[0] ); + + /* + * newer than cookieCSN (srs->sr_state.ctxcsn) + */ + cmp = 1; + for ( i=0; isr_state.numcsns; i++ ) { + if ( sid == srs->sr_state.sids[i] ) { + cmp = ber_bvcmp( &csn[0], &srs->sr_state.ctxcsn[i] ); + break; + } + } + if ( cmp <= 0 ) { + Debug( LDAP_DEBUG_SYNC, "%s syncprov_accesslog_uuid_cb: " + "cmp %d, csn %s too old\n", + op->o_log_prefix, cmp, srs->sr_state.ctxcsn[i].bv_val ); + return rs->sr_err; + } + + /* + * not newer than snapshot ctxcsn (uuid_progress->ctxcsn) + */ + cmp = 0; + for ( i=0; inumcsns; i++ ) { + if ( sid == uuid_progress->sids[i] ) { + cmp = ber_bvcmp( &csn[0], &uuid_progress->ctxcsn[i] ); + break; + } + } + if ( cmp > 0 ) { + Debug( LDAP_DEBUG_SYNC, "%s syncprov_accesslog_uuid_cb: " + "cmp %d, csn %s too new\n", + op->o_log_prefix, cmp, srs->sr_state.ctxcsn[i].bv_val ); + return rs->sr_err; + } + + a = attr_find( attrs, ad_reqEntryUUID ); + if ( !a || a->a_numvals == 0 ) { + rs->sr_err = LDAP_CONSTRAINT_VIOLATION; + return rs->sr_err; + } + uuid[0] = a->a_nvals[0]; + + bv = avl_find( uuid_progress->uuids, uuid, sp_uuid_cmp ); + if ( bv ) { + /* Already checked or sent, no change */ + Debug( LDAP_DEBUG_SYNC, "%s syncprov_accesslog_uuid_cb: " + "uuid %s already checked\n", + op->o_log_prefix, a->a_vals[0].bv_val ); + return rs->sr_err; + } + + if ( !is_delete ) { + is_delete = check_uuidlist_presence( uuid_progress->op, uuid, 1, 1 ); + } + Debug( LDAP_DEBUG_SYNC, "%s syncprov_accesslog_uuid_cb: " + "uuid %s is %s present\n", + op->o_log_prefix, a->a_vals[0].bv_val, + is_delete ? "no longer" : "still" ); + + i = uuid_progress->ndel++; + + bv = &uuid_progress->uuid_list[i]; + bv->bv_val = &uuid_progress->uuid_buf[i*UUID_LEN]; + bv->bv_len = a->a_nvals[0].bv_len; + AC_MEMCPY( bv->bv_val, a->a_nvals[0].bv_val, a->a_nvals[0].bv_len ); + + rc = avl_insert( &uuid_progress->uuids, bv, sp_uuid_cmp, avl_dup_error ); + assert( rc == LDAP_SUCCESS ); + + if ( is_delete ) { + struct berval cookie; + + slap_compose_sync_cookie( op, &cookie, srs->sr_state.ctxcsn, + srs->sr_state.rid, slap_serverID ? slap_serverID : -1, csn ); + syncprov_sendinfo( uuid_progress->op, uuid_progress->rs, + LDAP_TAG_SYNC_ID_SET, &cookie, 0, uuid, 1 ); + op->o_tmpfree( cookie.bv_val, op->o_tmpmemctx ); + } + + if ( uuid_progress->ndel >= uuid_progress->list_len ) { + int ndel; + + assert( uuid_progress->ndel == uuid_progress->list_len ); + ndel = avl_free( uuid_progress->uuids, NULL ); + assert( ndel == uuid_progress->ndel ); + uuid_progress->ndel = 0; + } + + return rs->sr_err; +} + static int syncprov_play_sessionlog( Operation *op, SlapReply *rs, sync_control *srs, BerVarray ctxcsn, int numcsns, int *sids, @@ -1994,6 +2162,127 @@ syncprov_play_sessionlog( Operation *op, SlapReply *rs, sync_control *srs, return LDAP_SUCCESS; } +static int +syncprov_play_accesslog( Operation *op, SlapReply *rs, sync_control *srs, + BerVarray ctxcsn, int numcsns, int *sids, + struct berval *mincsn, int minsid ) +{ + slap_overinst *on = (slap_overinst *)op->o_bd->bd_info; + syncprov_info_t *si = on->on_bi.bi_private; + Operation fop; + SlapReply frs = { REP_RESULT }; + slap_callback cb = {}; + Filter *f; + syncprov_accesslog_deletes uuid_progress = { + .op = op, + .rs = rs, + .srs = srs, + .ctxcsn = ctxcsn, + .numcsns = numcsns, + .sids = sids, + }; + struct berval oldestcsn = BER_BVNULL, newestcsn = ctxcsn[0], + basedn, filterpattern = BER_BVC( + "(&" + "(entryCSN>=%s)" + "(entryCSN<=%s)" + "(reqResult=0)" + "(reqDN:dnSubtreeMatch:=%s)" + "(|" + "(objectclass=auditWriteObject)" + "(objectclass=auditExtended)" + "))" ); + BackendDB *db; + Entry *e; + Attribute *a; + int i, rc = -1; + + assert( !BER_BVISNULL( &si->si_logbase ) ); + + for ( i=1; i < numcsns; i++ ) { + if ( ber_bvcmp( &newestcsn, &ctxcsn[i] ) < 0 ) { + newestcsn = ctxcsn[i]; + } + } + + db = select_backend( &si->si_logbase, 0 ); + if ( !db ) { + Debug( LDAP_DEBUG_ANY, "%s syncprov_play_accesslog: " + "No database configured to hold accesslog dn=%s\n", + op->o_log_prefix, si->si_logbase.bv_val ); + return LDAP_NO_SUCH_OBJECT; + } + + fop = *op; + fop.o_sync_mode = 0; + fop.o_bd = db; + rc = be_entry_get_rw( &fop, &si->si_logbase, NULL, ad_minCSN, 0, &e ); + if ( rc ) { + return rc; + } + + a = attr_find( e->e_attrs, ad_minCSN ); + if ( !a ) { + be_entry_release_rw( &fop, e, 0 ); + return LDAP_NO_SUCH_ATTRIBUTE; + } + for ( i=0; i < a->a_numvals; i++ ) { + if ( BER_BVISEMPTY( &oldestcsn ) || + ber_bvcmp( &oldestcsn, &a->a_nvals[i] ) > 0 ) { + oldestcsn = a->a_nvals[i]; + } + } + + filter_escape_value_x( &op->o_req_ndn, &basedn, fop.o_tmpmemctx ); + fop.o_req_ndn = fop.o_req_dn = si->si_logbase; + fop.ors_filterstr.bv_val = fop.o_tmpalloc( + filterpattern.bv_len + + oldestcsn.bv_len + newestcsn.bv_len + basedn.bv_len, + fop.o_tmpmemctx ); + fop.ors_filterstr.bv_len = sprintf( fop.ors_filterstr.bv_val, + filterpattern.bv_val, + oldestcsn.bv_val, newestcsn.bv_val, basedn.bv_val ); + Debug( LDAP_DEBUG_SYNC, "%s syncprov_play_accesslog: " + "prepared filter '%s', base='%s'\n", + op->o_log_prefix, fop.ors_filterstr.bv_val, si->si_logbase.bv_val ); + f = str2filter_x( &fop, fop.ors_filterstr.bv_val ); + fop.ors_filter = f; + + fop.o_tmpfree( basedn.bv_val, fop.o_tmpmemctx ); + be_entry_release_rw( &fop, e, 0 ); + + /* + * Allocate memory for list_len uuids for use by the callback, populate + * with entries that we have sent or checked still match the filter. + * A disappearing entry gets its uuid sent as a delete. + * + * in the callback, we need: + * - original op and rs so we can send the message + * - sync_control + * - the uuid buffer and list and their length + * - number of uuids we already have in the list + * - the lookup structure so we don't have to check/send a uuid twice + * (AVL?) + */ + uuid_progress.list_len = SLAP_SYNCUUID_SET_SIZE; + uuid_progress.uuid_list = fop.o_tmpalloc( (uuid_progress.list_len) * sizeof(struct berval), fop.o_tmpmemctx ); + uuid_progress.uuid_buf = fop.o_tmpalloc( (uuid_progress.list_len) * UUID_LEN, fop.o_tmpmemctx ); + + cb.sc_private = &uuid_progress; + cb.sc_response = syncprov_accesslog_uuid_cb; + + fop.o_callback = &cb; + + rc = fop.o_bd->be_search( &fop, &frs ); + + fop.o_tmpfree( uuid_progress.uuid_buf, fop.o_tmpmemctx ); + fop.o_tmpfree( uuid_progress.uuid_list, fop.o_tmpmemctx ); + fop.o_tmpfree( fop.ors_filterstr.bv_val, fop.o_tmpmemctx ); + filter_free_x( &fop, f, 1 ); + + return rc; +} + static int syncprov_new_ctxcsn( opcookie *opc, syncprov_info_t *si, int csn_changed, int numvals, BerVarray vals ) { @@ -2933,7 +3222,13 @@ no_change: if ( !(op->o_sync_mode & SLAP_SYNC_PERSIST) ) { goto shortcut; } - if ( si->si_logs ) { + if ( !BER_BVISNULL( &si->si_logbase ) ) { + do_present = 0; + if ( syncprov_play_accesslog( op, rs, srs, ctxcsn, + numcsns, sids, &mincsn, minsid ) ) { + do_present = SS_PRESENT; + } + } else if ( si->si_logs ) { do_present = 0; if ( syncprov_play_sessionlog( op, rs, srs, ctxcsn, numcsns, sids, &mincsn, minsid ) ) { @@ -3122,11 +3417,66 @@ syncprov_operational( return SLAP_CB_CONTINUE; } +static int +syncprov_setup_accesslog(void) +{ + const char *text; + int rc = -1; + + if ( !ad_reqType ) { + if ( slap_str2ad( "reqType", &ad_reqType, &text ) ) { + Debug( LDAP_DEBUG_ANY, "syncprov_setup_accesslog: " + "couldn't get definition for attribute reqType, " + "is accessslog configured?\n" ); + return rc; + } + } + + if ( !ad_reqResult ) { + if ( slap_str2ad( "reqResult", &ad_reqResult, &text ) ) { + Debug( LDAP_DEBUG_ANY, "syncprov_setup_accesslog: " + "couldn't get definition for attribute reqResult, " + "is accessslog configured?\n" ); + return rc; + } + } + + if ( !ad_reqDN ) { + if ( slap_str2ad( "reqDN", &ad_reqDN, &text ) ) { + Debug( LDAP_DEBUG_ANY, "syncprov_setup_accesslog: " + "couldn't get definition for attribute reqDN, " + "is accessslog configured?\n" ); + return rc; + } + } + + if ( !ad_reqEntryUUID ) { + if ( slap_str2ad( "reqEntryUUID", &ad_reqEntryUUID, &text ) ) { + Debug( LDAP_DEBUG_ANY, "syncprov_setup_accesslog: " + "couldn't get definition for attribute reqEntryUUID, " + "is accessslog configured?\n" ); + return rc; + } + } + + if ( !ad_minCSN ) { + if ( slap_str2ad( "minCSN", &ad_minCSN, &text ) ) { + Debug( LDAP_DEBUG_ANY, "syncprov_setup_accesslog: " + "couldn't get definition for attribute minCSN, " + "is accessslog configured?\n" ); + return rc; + } + } + + return LDAP_SUCCESS; +} + enum { SP_CHKPT = 1, SP_SESSL, SP_NOPRES, - SP_USEHINT + SP_USEHINT, + SP_LOGDB }; static ConfigDriver sp_cf_gen; @@ -3152,6 +3502,10 @@ static ConfigTable spcfg[] = { "DESC 'Observe Reload Hint in Request control' " "EQUALITY booleanMatch " "SYNTAX OMsBoolean SINGLE-VALUE )", NULL, NULL }, + { "syncprov-sessionlog-source", NULL, 2, 2, 0, ARG_DN|ARG_MAGIC|SP_LOGDB, + sp_cf_gen, "( OLcfgOvAt:1.5 NAME 'olcSpSessionlogSource' " + "DESC 'On startup, try loading sessionlog from this subtree' " + "SYNTAX OMsDN SINGLE-VALUE )", NULL, NULL }, { NULL, NULL, 0, 0, 0, ARG_IGNORED } }; @@ -3164,6 +3518,7 @@ static ConfigOCs spocs[] = { "$ olcSpSessionlog " "$ olcSpNoPresent " "$ olcSpReloadHint " + "$ olcSpSessionlogSource " ") )", Cft_Overlay, spcfg }, { NULL, 0, NULL } @@ -3217,6 +3572,14 @@ sp_cf_gen(ConfigArgs *c) rc = 1; } break; + case SP_LOGDB: + if ( BER_BVISEMPTY( &si->si_logbase ) ) { + rc = 1; + } else { + value_add_one( &c->rvalue_vals, &si->si_logbase ); + value_add_one( &c->rvalue_nvals, &si->si_logbase ); + } + break; } return rc; } else if ( c->op == LDAP_MOD_DELETE ) { @@ -3234,6 +3597,12 @@ sp_cf_gen(ConfigArgs *c) case SP_USEHINT: si->si_usehint = 0; break; + case SP_LOGDB: + if ( !BER_BVISNULL( &si->si_logbase ) ) { + ch_free( si->si_logbase.bv_val ); + BER_BVZERO( &si->si_logbase ); + } + break; } return rc; } @@ -3280,8 +3649,14 @@ sp_cf_gen(ConfigArgs *c) "%s: %s\n", c->log, c->cr_msg ); return ARG_BAD_CONF; } + if ( size && !BER_BVISNULL( &si->si_logbase ) ) { + Debug( LDAP_DEBUG_ANY, "syncprov_config: while configuring " + "internal sessionlog, accesslog source has already been " + "configured, this results in wasteful operation\n" ); + } sl = si->si_logs; if ( !sl ) { + if ( !size ) break; sl = ch_calloc( 1, sizeof( sessionlog )); ldap_pvt_thread_mutex_init( &sl->sl_mutex ); si->si_logs = sl; @@ -3295,6 +3670,28 @@ sp_cf_gen(ConfigArgs *c) case SP_USEHINT: si->si_usehint = c->value_int; break; + case SP_LOGDB: + if ( si->si_logs ) { + Debug( LDAP_DEBUG_ANY, "syncprov_config: while configuring " + "accesslog source, internal sessionlog has already been " + "configured, this results in wasteful operation\n" ); + } + if ( CONFIG_ONLINE_ADD( c ) ) { + if ( !select_backend( &c->value_ndn, 0 ) ) { + snprintf( c->cr_msg, sizeof( c->cr_msg ), + "<%s> no matching backend found for suffix", + c->argv[0] ); + Debug( LDAP_DEBUG_ANY, "%s: %s \"%s\"\n", + c->log, c->cr_msg, c->value_dn.bv_val ); + rc = 1; + break; + } + ch_free( c->value_ndn.bv_val ); + } + si->si_logbase = c->value_ndn; + rc = syncprov_setup_accesslog(); + ch_free( c->value_dn.bv_val ); + break; } return rc; } @@ -3429,6 +3826,16 @@ syncprov_db_open( sl->sl_sids[i] = si->si_sids[i]; } + if ( !BER_BVISNULL( &si->si_logbase ) ) { + BackendDB *db = select_backend( &si->si_logbase, 0 ); + if ( !db ) { + Debug( LDAP_DEBUG_ANY, "syncprov_db_open: " + "configured accesslog database dn='%s' not present\n", + si->si_logbase.bv_val ); + return -1; + } + } + out: op->o_bd->bd_info = (BackendInfo *)on; return 0; -- 2.47.2