Skip to content

Commit

Permalink
Issue 6347 - better fix for desyncronized vlv cache
Browse files Browse the repository at this point in the history
  • Loading branch information
@progier389
progier389 committed Oct 9, 2024
1 parent 145e7f4 commit b026108
Show file tree
Hide file tree
Showing 8 changed files with 458 additions and 77 deletions.
56 changes: 36 additions & 20 deletions ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,7 @@ static inline void log_stack(int loglvl)
}
}

void dbi_str(MDB_cursor *cursor, int dbi, char *dbistr)
void dbi_str(MDB_cursor *cursor, int dbi, char dbistr[DBISTRMAXSIZE])
{
const char *str = "?";
dbmdb_dbi_t * dbi1;
Expand All @@ -161,7 +161,7 @@ void dbi_str(MDB_cursor *cursor, int dbi, char *dbistr)
if (dbi1 && dbi1->dbname) {
str = dbi1->dbname;
}
PR_snprintf(dbistr, DBGVAL2STRMAXSIZE, "dbi: %d <%s>", dbi, str);
PR_snprintf(dbistr, DBISTRMAXSIZE, "dbi: %d <%s>", dbi, str);
}

#ifdef DBMDB_DEBUG
Expand Down Expand Up @@ -297,7 +297,7 @@ dbg_mdb_cursor_open(const char *file, int lineno, const char *funcname, MDB_txn
{
int rc = mdb_cursor_open(txn, dbi, cursor);
if (dbg_should_log(DBGMDB_LEVEL_MDBAPI, dbi, NULL)) {
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];
dbi_str(NULL, dbi, dbistr);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_MDBAPI+DBGMDB_LEVEL_FORCE, "mdb_cursor_open(txn: %p, %s, cursor: %p)=%d", txn, dbistr, *cursor, rc);
}
Expand All @@ -318,7 +318,7 @@ void
dbg_mdb_cursor_close(const char *file, int lineno, const char *funcname, MDB_cursor *cursor)
{
if (dbg_should_log(DBGMDB_LEVEL_MDBAPI, 0, cursor)) {
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];
dbi_str(cursor, 0, dbistr);
mdb_cursor_close(cursor);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_MDBAPI+DBGMDB_LEVEL_FORCE, "mdb_cursor_close(cursor: %p) %s", cursor, dbistr);
Expand All @@ -336,7 +336,7 @@ __dbg_mdb_cursor_get(const char *file, int lineno, const char *funcname, int log
char datastr[DBGVAL2STRMAXSIZE];
char flagsstr[DBGVAL2STRMAXSIZE];
char cursorstr[DBGVAL2STRMAXSIZE];
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];
int sl = 0;
if (dbg_should_log(loglvl, 0, cursor)) {
dbi_str(cursor, 0, dbistr);
Expand Down Expand Up @@ -376,7 +376,7 @@ if (data->mv_size <= 511) return 0;
char keystr[DBGVAL2STRMAXSIZE];
char datastr[DBGVAL2STRMAXSIZE];
char flagsstr[DBGVAL2STRMAXSIZE];
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];

dbi_str(NULL, dbi, dbistr);
dbgval2str(keystr, sizeof keystr, key);
Expand All @@ -394,7 +394,7 @@ dbg_mdb_get(const char *file, int lineno, const char *funcname, MDB_txn *txn, MD
{
char keystr[DBGVAL2STRMAXSIZE];
char datastr[DBGVAL2STRMAXSIZE];
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];

if (dbg_should_log(DBGMDB_LEVEL_MDBAPI, dbi, NULL)) {
dbi_str(NULL, dbi, dbistr);
Expand All @@ -419,7 +419,7 @@ dbg_mdb_del(const char *file, int lineno, const char *funcname, MDB_txn *txn, MD
if (dbg_should_log(DBGMDB_LEVEL_MDBAPI, dbi, NULL)) {
char keystr[DBGVAL2STRMAXSIZE];
char datastr[DBGVAL2STRMAXSIZE];
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];

dbi_str(NULL, dbi, dbistr);
dbgval2str(keystr, sizeof keystr, key);
Expand All @@ -438,7 +438,7 @@ dbg_mdb_cursor_put(const char *file, int lineno, const char *funcname, MDB_curso
char datastr[DBGVAL2STRMAXSIZE];
char flagsstr[DBGVAL2STRMAXSIZE];
char cursorstr[DBGVAL2STRMAXSIZE];
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];

dbi_str(cursor, 0, dbistr);
dbgval2str(keystr, sizeof keystr, key);
Expand Down Expand Up @@ -467,32 +467,46 @@ dbg_mdb_drop(const char *file, int lineno, const char *funcname, MDB_txn *txn, M
{
int rc = mdb_drop(txn, dbi, del);
if (dbg_should_log(DBGMDB_LEVEL_MDBAPI, dbi, NULL)) {
char dbistr[DBGVAL2STRMAXSIZE];
char dbistr[DBISTRMAXSIZE];
dbi_str(NULL, dbi, dbistr);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_MDBAPI+DBGMDB_LEVEL_FORCE, "mdb_drop(txn: %p, %s, del: %d)=%d", txn, dbistr, del, rc);
}
return rc;
}

int txn_loglvl()
{
if (dbgmdb_level & DBGMDB_LEVEL_MDBAPI) {
return DBGMDB_LEVEL_MDBAPI;
}
if (dbgmdb_level & DBGMDB_LEVEL_TXN) {
return DBGMDB_LEVEL_TXN;
}
return 0;
}

int dbg_txn_begin(const char *file, int lineno, const char *funcname, MDB_env *env, MDB_txn *parent_txn, int flags, MDB_txn **txn)
{
if (!(dbgmdb_level & DBGMDB_LEVEL_TXN)) {
int lvl = txn_loglvl();
if (lvl == 0) {
return mdb_txn_begin(env, parent_txn, flags, txn);
}
char strflags[100];
dbmdb_envflags2str(flags, strflags, sizeof strflags);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "TXN_BEGIN[%d]. txn_parent=%p, %s, stack is:", pthread_gettid(), parent_txn, strflags);
dbg_log(file, lineno, funcname, lvl, "TXN_BEGIN[%d]. txn_parent=%p, %s, stack is:", pthread_gettid(), parent_txn, strflags);
log_stack(DBGMDB_LEVEL_TXN);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "Waiting ...\n");
dbg_log(file, lineno, funcname, lvl, "Waiting ...\n");
int rc = mdb_txn_begin(env, parent_txn, flags, txn);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "Done. txn_begin(env=%p, txn_parent=%p, flags=0x%x, txn=0x%p) returned %d.",
dbg_log(file, lineno, funcname, lvl, "Done. txn_begin(env=%p, txn_parent=%p, flags=0x%x, txn=0x%p) returned %d.",
env, parent_txn, flags, *txn, rc);
return rc;
}

int dbg_txn_end(const char *file, int lineno, const char *funcname, MDB_txn *txn, int iscommit)
{
if (!(dbgmdb_level & DBGMDB_LEVEL_TXN)) {
int lvl = txn_loglvl();
char *stackis = (lvl == DBGMDB_LEVEL_TXN) ? " stack is:" : "";
if (lvl == 0) {
if (iscommit) {
return mdb_txn_commit(txn);
} else {
Expand All @@ -503,27 +517,29 @@ int dbg_txn_end(const char *file, int lineno, const char *funcname, MDB_txn *txn
int rc = 0;
if (iscommit) {
rc = mdb_txn_commit(txn);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "TXN_COMMIT[%d] (txn=0x%p) returned %d. stack is:", pthread_gettid(), txn, rc);
dbg_log(file, lineno, funcname, lvl, "TXN_COMMIT[%d] (txn=0x%p) returned %d.%s", pthread_gettid(), txn, rc, stackis);
} else {
mdb_txn_abort(txn);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "TXN_ABORT[%d] (txn=0x%p). stack is:", pthread_gettid(), txn);
dbg_log(file, lineno, funcname, lvl, "TXN_ABORT[%d] (txn=0x%p).%s", pthread_gettid(), txn, stackis);
}
if (lvl == DBGMDB_LEVEL_TXN) {
log_stack(DBGMDB_LEVEL_TXN);
}
return rc;
}


void dbg_txn_reset(const char *file, int lineno, const char *funcname, MDB_txn *txn)
{
mdb_txn_reset(txn);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "TXN_RESET[%d] (txn=0x%p). stack is:", pthread_gettid(), txn);
dbg_log(file, lineno, funcname, txn_loglvl(), "TXN_RESET[%d] (txn=0x%p). stack is:", pthread_gettid(), txn);
log_stack(DBGMDB_LEVEL_TXN);
}

int dbg_txn_renew(const char *file, int lineno, const char *funcname, MDB_txn *txn)
{
int rc = mdb_txn_renew(txn);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_TXN, "TXN_RENEW[%d] (txn=0x%p) returned %d. stack is:", pthread_gettid(), txn, rc);
dbg_log(file, lineno, funcname, txn_loglvl(), "TXN_RENEW[%d] (txn=0x%p) returned %d. stack is:", pthread_gettid(), txn, rc);
log_stack(DBGMDB_LEVEL_TXN);
return rc;
}
Expand All @@ -533,7 +549,7 @@ void dbmdb_log_dbi_set_fn(const char *file, int lineno, const char *funcname, co
Dl_info info = {0};
dladdr(fn, &info);
/* Cannot use dbi_str here because slot is not yet up2date (so dbname is an argument) */
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_MDBAPI, "%s(txn=0x%p, dbi=%d <%s>, fn=0x%p <%s>)\n", action, txn, dbi, dbname, fn, info.dli_sname);
dbg_log(file, lineno, funcname, DBGMDB_LEVEL_MDBAPI, "%s(txn=0x%p, dbi=%d <%s>, fn=0x%p <%s>)\n", action, txn, dbi, dbname, fn, info.dli_sname);
}

int dbg_mdb_bulkop_cursor_get(const char *file, int lineno, const char *funcname, MDB_cursor *cursor, MDB_val *key, MDB_val *data, MDB_cursor_op op)
Expand Down
2 changes: 2 additions & 0 deletions ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,11 +20,13 @@ void dbmdb_format_dbslist_info(char *info, dbmdb_dbi_t *dbi);

#define DBGMDB_LEVEL_PRINTABLE 0xfff

#define DBISTRMAXSIZE 80

extern int dbgmdb_level; /* defined in mdb_debug.c */
void dbg_log(const char *file, int lineno, const char *funcname, int loglevel, char *fmt, ...);
void dbgval2str(char *buff, size_t bufsiz, MDB_val *val);
void dbmdb_dbg_set_dbi_slots(dbmdb_dbi_t *slots);
void dbi_str(MDB_cursor *cursor, int dbi, char dbistr[DBISTRMAXSIZE]);

/* #define DBMDB_DEBUG 1 */
#define DBGMDB_LEVEL_DEFAULT DBGMDB_LEVEL_MDBAPI+DBGMDB_LEVEL_TXN+DBGMDB_LEVEL_IMPORT+ \
Expand Down
1 change: 1 addition & 0 deletions ldap/servers/slapd/back-ldbm/db-mdb/mdb_import_threads.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3413,6 +3413,7 @@ dbmdb_add_import_index(ImportCtx_t *ctx, const char *name, IndexInfo *ii)
}
}

DBG_LOG(DBGMDB_LEVEL_OTHER,"Calling dbmdb_open_dbi_from_filename for %s flags = 0x%x", mii->name, dbi_flags);
dbmdb_open_dbi_from_filename(&mii->dbi, job->inst->inst_be, mii->name, mii->ai, dbi_flags);
avl_insert(&ctx->indexes, mii, cmp_mii, NULL);
}
Expand Down
15 changes: 15 additions & 0 deletions ldap/servers/slapd/back-ldbm/db-mdb/mdb_instance.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1245,6 +1245,8 @@ int dbmdb_open_dbi_from_filename(dbmdb_dbi_t **dbi, backend *be, const char *fil
dbi_open_ctx_t octx = {0};
dbi_txn_t *txn = NULL;
int rc = 0;
DBG_LOG(DBGMDB_LEVEL_OTHER, "dbmdb_open_dbi_from_filename: filename=%s flags=0x%x", filename, flags);


if (ctx->readonly || (flags&MDB_RDONLY)) {
flags &= ~MDB_CREATE;
Expand Down Expand Up @@ -1292,32 +1294,40 @@ int dbmdb_open_dbi_from_filename(dbmdb_dbi_t **dbi, backend *be, const char *fil
}
}
if (rc) {
DBG_LOG(DBGMDB_LEVEL_OTHER, "returning %d", rc);
return rc;
}
if (!*dbi) {
DBG_LOG(DBGMDB_LEVEL_OTHER, "returning MDB_NOTFOUND");
return MDB_NOTFOUND;
}
DBG_LOG(DBGMDB_LEVEL_OTHER, "So far rc = %d", rc);
if (ai && ai->ai_key_cmp_fn != (*dbi)->cmp_fn) {
if (! (*dbi)->cmp_fn) {
rc = dbmdb_update_dbi_cmp_fn(ctx, *dbi, ai->ai_key_cmp_fn, NULL);
}
(*dbi)->cmp_fn = ai->ai_key_cmp_fn;
}
DBG_LOG(DBGMDB_LEVEL_OTHER, "So far rc = %d", rc);

if (((*dbi)->state.state & DBIST_DIRTY) && !(flags & MDB_OPEN_DIRTY_DBI)) {
DBG_LOG(DBGMDB_LEVEL_OTHER, "returning MDB_NOTFOUND");
return MDB_NOTFOUND;
}
if (!rc && !((*dbi)->state.state & DBIST_DIRTY) && (flags & MDB_MARK_DIRTY_DBI)) {
dbistate_t st = (*dbi)->state;
st.state |= DBIST_DIRTY;
rc = dbmdb_update_dbi_state(ctx, *dbi, &st, NULL, PR_FALSE);
}
DBG_LOG(DBGMDB_LEVEL_OTHER, "So far rc = %d", rc);
if (!rc && (flags & MDB_TRUNCATE_DBI)) {
octx.ctx = ctx;
octx.dbi = *dbi;
octx.deletion_flags = 0;
DBG_LOG(DBGMDB_LEVEL_OTHER, "truncating db");
rc = dbi_remove(&octx);
}
DBG_LOG(DBGMDB_LEVEL_OTHER, "returning rc=%d", rc);
return rc;
}

Expand Down Expand Up @@ -1401,11 +1411,14 @@ int dbmdb_recno_cache_get_mode(dbmdb_recno_cache_ctx_t *rcctx)
rc = MDB_GET(txn, rcctx->rcdbi->dbi, &rcctx->key, &rcctx->data);
if (rc == MDB_SUCCESS) {
rcctx->mode = RCMODE_USE_CURSOR_TXN;
DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_recno_cache_get_mode(%s) mode=RCMODE_USE_CURSOR_TXN rc=0", rcdbname);
return rc;
}
if (rc != MDB_NOTFOUND) {
/* There was an error or cache is valid.
* Im both cases there is no need to rebuilt the cache.
*/
DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_recno_cache_get_mode(%s) mode=RCMODE_UNKNOWN rc=%d", rcdbname, rc);
return rc;
}
}
Expand All @@ -1415,7 +1428,9 @@ int dbmdb_recno_cache_get_mode(dbmdb_recno_cache_ctx_t *rcctx)
TXN_ABORT(txn);
txn = NULL;
rcctx->mode = RCMODE_USE_SUBTXN;
DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_recno_cache_get_mode(%s) mode=RCMODE_USE_SUBTXN rc=0", rcdbname);
} else if (rc == EINVAL) {
DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_recno_cache_get_mode(%s) mode=RCMODE_USE_NEW_THREAD rc=0", rcdbname);
rcctx->mode = RCMODE_USE_NEW_THREAD;
rc = 0;
}
Expand Down
Loading

0 comments on commit b026108

Please sign in to comment.