ITS#6467 Make accesslog a possible sessionlog source

This commit is contained in:
Ondřej Kuzník 2018-10-09 13:00:49 +02:00 committed by Ondřej Kuzník
parent 66a743f119
commit 43ebfa8fb4
2 changed files with 417 additions and 2 deletions

View File

@ -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 <dn>
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

View File

@ -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; i<srs->sr_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; i<uuid_progress->numcsns; 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;