diff --git a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.c b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.c index 3ccff4c2cf..33e71f1a8a 100644 --- a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.c +++ b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.c @@ -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; @@ -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 @@ -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); } @@ -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); @@ -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); @@ -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); @@ -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); @@ -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); @@ -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); @@ -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 { @@ -503,12 +517,14 @@ 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; } @@ -516,14 +532,14 @@ int dbg_txn_end(const char *file, int lineno, const char *funcname, MDB_txn *txn 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; } @@ -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) diff --git a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.h b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.h index e25d775099..3bd709a4c6 100644 --- a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.h +++ b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_debug.h @@ -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+ \ diff --git a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_import_threads.c b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_import_threads.c index f03e6741b1..9504c24343 100644 --- a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_import_threads.c +++ b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_import_threads.c @@ -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); } diff --git a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_instance.c b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_instance.c index 66e6e0e8de..50db548d95 100644 --- a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_instance.c +++ b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_instance.c @@ -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; @@ -1292,19 +1294,24 @@ 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)) { @@ -1312,12 +1319,15 @@ int dbmdb_open_dbi_from_filename(dbmdb_dbi_t **dbi, backend *be, const char *fil 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; } @@ -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; } } @@ -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; } diff --git a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_layer.c b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_layer.c index 313eb35aec..e4bf27b96c 100644 --- a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_layer.c +++ b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_layer.c @@ -2108,6 +2108,7 @@ void *dbmdb_recno_cache_build(void *arg) int len = 0; int rc = 0; + DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_recno_cache_build(%s)", rcctx->rcdbname); /* Open/creat cache dbi */ rc = dbmdb_open_dbi_from_filename(&rcctx->rcdbi, rcctx->cursor->be, rcctx->rcdbname, NULL, MDB_CREATE); slapi_ch_free_string(&rcctx->rcdbname); @@ -2131,63 +2132,46 @@ void *dbmdb_recno_cache_build(void *arg) txn_ctx.flags |= DBMDB_TXNCTX_NEED_COMMIT; } } + if (rc == 0) { + rc = MDB_CURSOR_GET(txn_ctx.cursor, &key, &data, MDB_FIRST); + recno = 1; + } while (rc == 0) { slapi_log_err(SLAPI_LOG_DEBUG, "dbmdb_recno_cache_build", "recno=%d\n", recno); - if (recno % RECNO_CACHE_INTERVAL != 1) { - recno++; - rc = MDB_CURSOR_GET(txn_ctx.cursor, &key, &data, MDB_NEXT); - continue; - } - /* close the txn from time to time to avoid locking all dbi page */ - rc = dbmdb_end_recno_cache_txn(&txn_ctx, 0); - rc |= dbmdb_begin_recno_cache_txn(rcctx, &txn_ctx, rcctx->dbi->dbi); - if (rc) { - break; - } - /* Reset to new cursor to the old position */ - if (recno == 1) { - rc = MDB_CURSOR_GET(txn_ctx.cursor, &key, &data, MDB_FIRST); - } else { - rc = MDB_CURSOR_GET(txn_ctx.cursor, &key, &data, MDB_SET); - if (rc == MDB_NOTFOUND) { - rc = MDB_CURSOR_GET(txn_ctx.cursor, &key, &data, MDB_SET_RANGE); - } - } - if (rc) { - break; - } - /* Prepare the cache data */ - len = sizeof(*rce) + data.mv_size + key.mv_size; - rce = (dbmdb_recno_cache_elmt_t*)slapi_ch_malloc(len); - rce->len = len; - rce->recno = recno; - rce->key.mv_size = key.mv_size; - rce->key.mv_data = &rce[1]; - rce->data.mv_size = data.mv_size; - rce->data.mv_data = ((char*)&rce[1])+rce->key.mv_size; - memcpy(rce->key.mv_data, key.mv_data, key.mv_size); - memcpy(rce->data.mv_data, data.mv_data, data.mv_size); - rcdata.mv_data = rce; - rcdata.mv_size = len; - dbmdb_generate_recno_cache_key_by_recno(&rckey, recno); - rc = MDB_PUT(txn_ctx.txn, rcctx->rcdbi->dbi, &rckey, &rcdata, 0); - slapi_ch_free(&rckey.mv_data); - if (rc) { - slapi_log_err(SLAPI_LOG_ERR, "dbmdb_recno_cache_build", - "Failed to write record in db %s, key=%s error: %s\n", - rcctx->rcdbi->dbname, (char*)(key.mv_data), mdb_strerror(rc)); - } else { - dbmdb_generate_recno_cache_key_by_data(&rckey, &key, &data); + if (recno % RECNO_CACHE_INTERVAL == 1) { + /* Prepare the cache data */ + len = sizeof(*rce) + data.mv_size + key.mv_size; + rce = (dbmdb_recno_cache_elmt_t*)slapi_ch_malloc(len); + rce->len = len; + rce->recno = recno; + rce->key.mv_size = key.mv_size; + rce->key.mv_data = &rce[1]; + rce->data.mv_size = data.mv_size; + rce->data.mv_data = ((char*)&rce[1])+rce->key.mv_size; + memcpy(rce->key.mv_data, key.mv_data, key.mv_size); + memcpy(rce->data.mv_data, data.mv_data, data.mv_size); + rcdata.mv_data = rce; + rcdata.mv_size = len; + dbmdb_generate_recno_cache_key_by_recno(&rckey, recno); rc = MDB_PUT(txn_ctx.txn, rcctx->rcdbi->dbi, &rckey, &rcdata, 0); slapi_ch_free(&rckey.mv_data); - txn_ctx.flags |= DBMDB_TXNCTX_NEED_COMMIT; if (rc) { slapi_log_err(SLAPI_LOG_ERR, "dbmdb_recno_cache_build", "Failed to write record in db %s, key=%s error: %s\n", rcctx->rcdbi->dbname, (char*)(key.mv_data), mdb_strerror(rc)); + } else { + dbmdb_generate_recno_cache_key_by_data(&rckey, &key, &data); + rc = MDB_PUT(txn_ctx.txn, rcctx->rcdbi->dbi, &rckey, &rcdata, 0); + slapi_ch_free(&rckey.mv_data); + txn_ctx.flags |= DBMDB_TXNCTX_NEED_COMMIT; + if (rc) { + slapi_log_err(SLAPI_LOG_ERR, "dbmdb_recno_cache_build", + "Failed to write record in db %s, key=%s error: %s\n", + rcctx->rcdbi->dbname, (char*)(key.mv_data), mdb_strerror(rc)); + } } + slapi_ch_free(&rcdata.mv_data); } - slapi_ch_free(&rcdata.mv_data); rc = MDB_CURSOR_GET(txn_ctx.cursor, &key, &data, MDB_NEXT); recno++; } @@ -2378,26 +2362,27 @@ int dbmdb_cursor_set_recno(dbi_cursor_t *cursor, MDB_val *dbmdb_key, MDB_val *db } memcpy(&recno, dbmdb_key->mv_data, sizeof (dbi_recno_t)); +#ifdef DBMDB_DEBUG + char dbistr[DBISTRMAXSIZE]; + dbi_str(cursor->cur, 0, dbistr); + DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_cursor_set_recno: recno=%d dbi=%s", recno, dbistr); +#endif dbmdb_generate_recno_cache_key_by_recno(&cache_key, recno); rc = dbmdb_recno_cache_lookup(cursor, &cache_key, &rce); if (rc ==0) { rc = MDB_CURSOR_GET(cursor->cur, &rce->key, &rce->data, MDB_SET_RANGE); } while (rc == 0 && recno > rce->recno) { - DBG_LOG(DBGMDB_LEVEL_VLV, "Current record index is %d Target is %d\n", rce->recno, recno); + DBG_LOG(DBGMDB_LEVEL_VLV, "Current record index is %d Target is %d", rce->recno, recno); rce->recno++; rc = MDB_CURSOR_GET(cursor->cur, &rce->key, &rce->data, MDB_NEXT); } - if (rc == MDB_NOTFOUND) { - /* Stay on last record if there are no more records */ - rc = 0; - } if (rc == 0 && dbmdb_data->mv_size == rce->data.mv_size) { /* Should always be the case */ - DBG_LOG(DBGMDB_LEVEL_VLV, "SUCCESS\n"); + DBG_LOG(DBGMDB_LEVEL_VLV, "SUCCESS"); memcpy(dbmdb_data->mv_data , rce->data.mv_data, dbmdb_data->mv_size); } else { - DBG_LOG(DBGMDB_LEVEL_VLV, "FAILURE: rc=%d dbmdb_data->mv_size=%d rce->data.mv_size=%d\n", rc, dbmdb_data->mv_size, rce->data.mv_size); + DBG_LOG(DBGMDB_LEVEL_VLV, "FAILURE: rc=%d dbmdb_data->mv_size=%d rce->data.mv_size=%d", rc, dbmdb_data->mv_size, rce->data.mv_size); } slapi_ch_free((void**)&rce); @@ -2878,6 +2863,7 @@ dbmdb_public_clear_vlv_cache(Slapi_Backend *be, dbi_txn_t *txn, dbi_db_t *db) MDB_val ok = { 0 }; int rc = 0; + DBG_LOG(DBGMDB_LEVEL_VLV, "dbmdb_public_clear_vlv_cache(%s)", rcdbname); ok.mv_data = "OK"; ok.mv_size = 2; rc = dbmdb_open_dbi_from_filename(&rcdbi, be, rcdbname, NULL, 0); diff --git a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_ldif2db.c b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_ldif2db.c index 548ad2910d..477a48ec95 100644 --- a/ldap/servers/slapd/back-ldbm/db-mdb/mdb_ldif2db.c +++ b/ldap/servers/slapd/back-ldbm/db-mdb/mdb_ldif2db.c @@ -1423,7 +1423,7 @@ _get_and_add_parent_rdns(backend *be, key.mv_data = &storedid; memset(&data, 0, sizeof(data)); - rc = mdb_get(TXN(cur->txn), cur->dbi->dbi, &key, &data); + rc = MDB_GET(TXN(cur->txn), cur->dbi->dbi, &key, &data); if (rc) { slapi_log_err(SLAPI_LOG_ERR, "_get_and_add_parent_rdns", "Failed to position cursor at ID " ID_FMT "\n", id); diff --git a/ldap/servers/slapd/back-ldbm/idl_new.c b/ldap/servers/slapd/back-ldbm/idl_new.c index 9c455f5df3..a1c1395bc2 100644 --- a/ldap/servers/slapd/back-ldbm/idl_new.c +++ b/ldap/servers/slapd/back-ldbm/idl_new.c @@ -939,7 +939,6 @@ idl_lmdb_range_fetch( /* Close the cursor */ if (0 == idl_range_ctx.flag_err) { idl_range_ctx.flag_err = ret; -slapi_log_err(SLAPI_LOG_INFO, "idl_lmdb_range_fetch", "flag_err=%d\n", idl_range_ctx.flag_err); } ret = dblayer_cursor_op(&cursor, DBI_OP_CLOSE, NULL, NULL); if (ret) { @@ -955,7 +954,6 @@ slapi_log_err(SLAPI_LOG_INFO, "idl_lmdb_range_fetch", "flag_err=%d\n", idl_range } if (0 == idl_range_ctx.flag_err) { idl_range_ctx.flag_err = ret; -slapi_log_err(SLAPI_LOG_INFO, "idl_lmdb_range_fetch", "flag_err=%d\n", idl_range_ctx.flag_err); } /* sort idl */ diff --git a/ldap/servers/slapd/tools/chkvlv.c b/ldap/servers/slapd/tools/chkvlv.c new file mode 100644 index 0000000000..2438021504 --- /dev/null +++ b/ldap/servers/slapd/tools/chkvlv.c @@ -0,0 +1,363 @@ +/** BEGIN COPYRIGHT BLOCK + * Copyright (C) 2024 Red Hat, Inc. + * All rights reserved. + * + * License: GPL (version 3 or any later version). + * See LICENSE for details. + * END COPYRIGHT BLOCK **/ + + +/* Build with: gcc -o chkvlv chkvlv.c -llmdb */ +/* Usage: chkvlv dbdir */ + +#include +#include +#include +#include +#include +#include +#include +#include +#include + + +#define T(expr) rc = expr; if (rc) { printf("%s[%d]: %s returned %s (%d)\n", __FILE__, __LINE__, #expr, mdb_strerror(rc), rc); exit(1); } + +#define RECNO_CACHE_PREFIX "/~recno-cache" +#define VLV_PREFIX "/vlv#" + + +typedef struct { + char *name; + MDB_dbi dbi; + int is_vlv; + int recno_idx; +} dbi_t; + +typedef struct { + MDB_val data; + MDB_val key; + int len; + uint32_t recno; + /* followed by key value then data value */ +} recno_elmt_t; + +typedef struct { + MDB_cursor *cur; + MDB_txn *txn; + MDB_val key; + MDB_val data; + int count; +} iterator_t; + + +int nbdbis; +dbi_t *dbis; +MDB_env *env = NULL; +MDB_dbi dbi = 0; + + +/* Iterate calling 'cb' callback on each database instance records */ +int +iterate(MDB_txn *txn, MDB_dbi dbi, int (*cb)(iterator_t *, void*), void *ctx) +{ + int rc = 0; + iterator_t it = {0}; + it.txn = txn; + T(mdb_cursor_open(txn, dbi, &it.cur)); + rc = mdb_cursor_get(it.cur, &it.key, &it.data, MDB_FIRST); + while (rc==0) { + rc = cb(&it, ctx); + if (rc == 0) { + it.count++; + rc = mdb_cursor_get(it.cur, &it.key, &it.data, MDB_NEXT); + } + } + mdb_cursor_close(it.cur); + if (rc == MDB_NOTFOUND) { + rc = 0; + } + return rc; +} + +void +open_db(const char *dbdir) +{ + int rc = 0; + char buf[200]; + char buf2[200]; + + FILE *fd = NULL; + size_t maxsize = 0; + MDB_dbi maxdbs = 0; + unsigned int maxreaders = 0; + char *pt = NULL; + + T(mdb_env_create(&env)); + sprintf(buf,"%s/INFO.mdb",dbdir); + fd = fopen(buf, "r"); + if (fd==NULL) { + perror(buf); + printf("The ' parameter is probably invalid.\n"); + exit(1); + } + while (pt=fgets(buf2, (sizeof buf2), fd)) { + sscanf(buf2, "MAXSIZE=%ld", &maxsize); + sscanf(buf2, "MAXREADERS=%ud", &maxreaders); + sscanf(buf2, "MAXDBS=%ud", &maxdbs); + } + fclose(fd); + + sprintf(buf,"%s/data.mdb",dbdir); + T(mdb_env_set_maxdbs(env, maxdbs)); + T(mdb_env_set_mapsize(env, maxsize)); + T(mdb_env_set_maxreaders(env, maxreaders)); + T(mdb_env_open(env, dbdir, MDB_RDONLY , 0700)); +} + +char * +dup_val(const MDB_val *val) +{ + char *str = malloc(val->mv_size+1); + if (str==NULL) { + fprintf(stderr, "Cannot alloc %ld bytes.\n", val->mv_size+1); + exit(1); + } + memcpy(str, val->mv_data, val->mv_size); + str[val->mv_size] = 0; + return str; +} + + +int +dup_recno_elmt(const MDB_val *val, recno_elmt_t *elmt) +{ + if (val->mv_size < sizeof *elmt) { + printf("Unexpected record size %ld (Should be >= %ld)\n", + val->mv_size, sizeof *elmt); + return -1; + } + memcpy(elmt, val->mv_data, sizeof *elmt); + size_t expected_size = (sizeof *elmt) + elmt->key.mv_size + elmt->data.mv_size; + if (val->mv_size != expected_size) { + printf("Unexpected record size %ld (Should be %ld)\n", + val->mv_size, expected_size); + elmt->key.mv_data = elmt->data.mv_data = NULL; + return -1; + } + char *pt = val->mv_data; + elmt->key.mv_data = pt+sizeof *elmt; + elmt->data.mv_data = pt+(sizeof *elmt)+elmt->key.mv_size; + elmt->key.mv_data = dup_val(&elmt->key); + elmt->data.mv_data = dup_val(&elmt->data); + return 0; +} + +void +free_recno_elmt(recno_elmt_t *elmt) +{ + if (elmt->key.mv_data) { + free(elmt->key.mv_data); + elmt->key.mv_data = NULL; + } + if (elmt->data.mv_data) { + free(elmt->data.mv_data); + elmt->data.mv_data = NULL; + } +} + +int +count_cb(iterator_t *it, void *ctx) +{ + *(int*)ctx = it->count; + return 0; +} + +int +store_dbi(iterator_t *it, void *ctx) +{ + int rc = 0; + if (it->count > nbdbis) { + return MDB_NOTFOUND; + } + char *name = dup_val(&it->key); + T(mdb_dbi_open(it->txn, name , 0, &dbis[it->count].dbi)); + dbis[it->count].name = name; + dbis[it->count].is_vlv = strstr(name, VLV_PREFIX) && !strstr(name, RECNO_CACHE_PREFIX); + return 0; +} + +void open_dbis() +{ + int rc = 0; + MDB_dbi dbi = 0; + MDB_txn *txn = 0; + + T(mdb_txn_begin(env, NULL, MDB_RDONLY, &txn)); + T(mdb_dbi_open(txn, "__DBNAMES", 0, &dbi)); + T(mdb_txn_commit(txn)); + T(mdb_txn_begin(env, NULL, MDB_RDONLY, &txn)); + T(iterate(txn, dbi, count_cb, &nbdbis)); + dbis = calloc(nbdbis, sizeof (dbi_t)); + if (!dbis) { + fprintf(stderr, "Cannot alloc %ld bytes.\n", nbdbis*sizeof (dbi_t)); + exit(1); + } + T(iterate(txn, dbi, store_dbi, NULL)); + T(mdb_txn_commit(txn)); + + for (size_t count = 0; count < nbdbis; count++) { + if (dbis[count].is_vlv) { + char buf2[200]; + char *pt = dbis[count].name; + char *pt2 = buf2; + while (*pt!='/') { + *pt2++ = *pt++; + } + strcpy(pt2,RECNO_CACHE_PREFIX); + pt2 += strlen(pt2); + strcpy(pt2,pt); + + for (size_t i = 0; i < nbdbis; i++) { + if (strcmp(dbis[i].name, buf2)==0) { + dbis[count].recno_idx = i; + } + } + } + } +} + +void +dump_val(const MDB_val *val) +{ + unsigned char *pt = val->mv_data; + for (size_t i = val->mv_size; i >0; i--) { + if ( *pt >= 0x32 && *pt < 0x7f && *pt != '\\') { + putchar(*pt); + } else { + printf("\\%02x", *pt); + } + pt++; + } +} + +int +cmp_val(const MDB_val *val1, const MDB_val *val2) +{ + size_t len = val1->mv_size > val2->mv_size ? val2->mv_size : val1->mv_size; + int rc = memcmp(val1->mv_data, val2->mv_data, len); + if (rc!=0) return rc; + return val1->mv_size - val2->mv_size; +} + +typedef struct { + dbi_t *vlvdbi; + recno_elmt_t *elmt; + iterator_t *it; + int found; +} check_recno_ctx_t; + +int +check_recno_ctx(iterator_t *it, void *ctx) +{ + check_recno_ctx_t *rctx = ctx; + if (cmp_val(&it->key, &rctx->elmt->key) == 0) { + rctx->found = 1; + if (it->count+1 != rctx->elmt->recno) { + printf("Problem (invalid recno value) detected in vlv cache record #%d\n", it->count); + printf("Found %d instead of %d\n", rctx->elmt->recno, it->count+1); + } + } + return 0; +} + +void +check_recno_record(iterator_t *it, dbi_t *vlvdbi, recno_elmt_t *elmt) +{ + int rc = 0; + check_recno_ctx_t ctx = {0}; + ctx.vlvdbi = vlvdbi; + ctx.elmt = elmt; + ctx.it = it; + if (dup_recno_elmt(&it->data, elmt)) { + printf("Problem (invalid data size) detected in vlv cache record #%d\n", it->count); + return; + } + T(iterate(it->txn, vlvdbi->dbi, check_recno_ctx, &ctx)); +} + +int +walk_cache(iterator_t *it, void *ctx) +{ + char *pt = it->key.mv_data; + recno_elmt_t elmt = {0}; + MDB_val vkey; + MDB_val vdata; + switch (*pt) { + case 'O': + printf("vlv cache is in sync.\n"); + return 0; + case 'D': + if (it->key.mv_size < sizeof vkey.mv_size) { + printf("Problem (invalid key size) detected in vlv cache record #%d\n", it->count); + return 0; + } + memcpy(&vkey.mv_size, pt + it->key.mv_size - sizeof vkey.mv_size, sizeof vkey.mv_size); + vkey.mv_data = pt+1; + vdata.mv_data = pt+1+vkey.mv_size; + vdata.mv_size = it->key.mv_size - 1-vkey.mv_size - sizeof vkey.mv_size; + printf("vkey: "); dump_val(&vkey); putchar('\n'); + printf("vdata: "); dump_val(&vdata); putchar('\n'); + check_recno_record(it, ctx, &elmt); + if (cmp_val(&vkey, &elmt.key) != 0) { + printf("Problem (missmatching key value) detected in vlv cache record #%d\n", it->count); + return 0; + } + if (cmp_val(&vdata, &elmt.data) != 0) { + printf("Problem (missmatching data value) detected in vlv cache record #%d\n", it->count); + return 0; + } + return 0; + case 'R': + if (it->key.mv_size !=11) { + printf("Problem (invalid key size) detected in vlv cache record #%d\n", it->count); + return 0; + } + check_recno_record(it, ctx, &elmt); + return 0; + } + + return 0; +} + +void +process_vlv(int idx) +{ + int rc = 0; + MDB_txn *txn = 0; + printf("Processing: %s\n", dbis[idx].name); + T(mdb_txn_begin(env, NULL, MDB_RDONLY, &txn)); + T(iterate(txn, dbis[dbis[idx].recno_idx].dbi, walk_cache, &dbis[idx])) + T(mdb_txn_commit(txn)); +} + + +int main(int argc, char **argv) +{ + int rc = 0; + if (argc != 2) { + printf("Usage: %s \n", argv[1]); + printf("\tThis tools check the lmdb vlv caches consistency\n") + exit(1); + } + char *dbdir = argv[1]; + + open_db(argv[1]); + open_dbis(); + for (size_t i = 0; i < nbdbis; i++) { + if (dbis[i].is_vlv) { + process_vlv(i); + } + } + return 0; +}