Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issue 6347 - better fix for desyncronized vlv cache #6358

Merged
merged 1 commit into from
Oct 10, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
56 changes: 36 additions & 20 deletions ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.c
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);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why not calling txn_loglvl() instead of DBGMDB_LEVEL_MDBAPI?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

txn_log() is used only for txn related function It allows to log when txn are open and closed when
DBGMDB_LEVEL_MDBAPI or DBGMDB_LEVEL_TXN is set but log txn backtrace only if DBGMDB_LEVEL_TXN is set

}

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
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
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
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
Loading