From 40ee895aaedd75622c4dad8f00830109dd477a33 Mon Sep 17 00:00:00 2001 From: Leonid Yuriev Date: Tue, 24 Sep 2019 02:07:00 +0300 Subject: [PATCH] mdbx: refine internal debug facilities. Change-Id: I934cb8587f07c59268b16a0dd99daeb7ac440e62 --- mdbx.h | 107 ++++++++++-------- src/elements/core.c | 228 +++++++++++++++++++++------------------ src/elements/internals.h | 158 +++++++++++++-------------- src/elements/lck-posix.c | 2 +- src/elements/osal.c | 2 +- test/keygen.cc | 4 +- test/log.cc | 54 ++++------ test/log.h | 18 ++-- test/main.cc | 2 +- test/test.cc | 6 +- test/ttl.cc | 6 +- 11 files changed, 305 insertions(+), 282 deletions(-) diff --git a/mdbx.h b/mdbx.h index 9db78013..202e3018 100644 --- a/mdbx.h +++ b/mdbx.h @@ -740,8 +740,68 @@ typedef struct iovec MDBX_val; * MDBX only store a 32 bit value for node sizes. */ #define MDBX_MAXDATASIZE INT32_MAX -/* A callback function used to compare two keys in a database */ -typedef int(MDBX_cmp_func)(const MDBX_val *a, const MDBX_val *b); +/*** DEBUG & LOGGING ********************************************************** + * Logging and runtime debug flags. + * + * NOTE: Most of debug feature enabled only if libmdbx builded with MDBX_DEBUG. + */ + +/* Log level (requires build libmdbx with MDBX_DEBUG) */ +#define MDBX_LOG_FATAL 0 /* critical conditions, i.e. assertion failures */ +#define MDBX_LOG_ERROR 1 /* error conditions */ +#define MDBX_LOG_WARN 2 /* warning conditions */ +#define MDBX_LOG_NOTICE 3 /* normal but significant condition */ +#define MDBX_LOG_VERBOSE 4 /* verbose informational */ +#define MDBX_LOG_DEBUG 5 /* debug-level messages */ +#define MDBX_LOG_TRACE 6 /* trace debug-level messages */ +#define MDBX_LOG_EXTRA 7 /* extra debug-level messages (dump pgno lists) */ + +/* Runtime debug flags. + * + * MDBX_DBG_DUMP and MDBX_DBG_LEGACY_MULTIOPEN always have an effect, + * but MDBX_DBG_ASSERT, MDBX_DBG_AUDIT and MDBX_DBG_JITTER only if libmdbx + * builded with MDBX_DEBUG. */ + +#define MDBX_DBG_ASSERT 1 /* Enable assertion checks */ +#define MDBX_DBG_AUDIT 2 /* Enable pages usage audit at commit transactions */ +#define MDBX_DBG_JITTER 4 /* Enable small random delays in critical points */ +#define MDBX_DBG_DUMP 8 /* Include or not database(s) in coredump files */ +#define MDBX_DBG_LEGACY_MULTIOPEN 16 /* Enable multi-opening environment(s) */ + +/* A debug-logger callback function, + * called before printing the message and aborting. + * + * [in] env An environment handle returned by mdbx_env_create(). + * [in] msg The assertion message, not including newline. */ +typedef void MDBX_debug_func(int loglevel, const char *function, int line, + const char *msg, va_list args); + +/* FIXME: Complete description */ +LIBMDBX_API int mdbx_setup_debug(int loglevel, int flags, + MDBX_debug_func *logger); + +/* A callback function for most MDBX assert() failures, + * called before printing the message and aborting. + * + * [in] env An environment handle returned by mdbx_env_create(). + * [in] msg The assertion message, not including newline. */ +typedef void MDBX_assert_func(const MDBX_env *env, const char *msg, + const char *function, unsigned line); + +/* Set or reset the assert() callback of the environment. + * + * Does nothing if libmdbx was built with MDBX_DEBUG=0 or with NDEBUG, + * and will return MDBX_ENOSYS in such case. + * + * [in] env An environment handle returned by mdbx_env_create(). + * [in] func An MDBX_assert_func function, or 0. + * + * Returns A non-zero error value on failure and 0 on success. */ +LIBMDBX_API int mdbx_env_set_assert(MDBX_env *env, MDBX_assert_func *func); + +/* FIXME: Complete description */ +LIBMDBX_API char *mdbx_dump_val(const MDBX_val *key, char *const buf, + const size_t bufsize); /**** THE FILES **************************************************************** * At the file system level, the environment corresponds to a pair of files. */ @@ -1981,25 +2041,6 @@ LIBMDBX_API int mdbx_env_set_userctx(MDBX_env *env, void *ctx); * Returns The pointer set by mdbx_env_set_userctx(). */ LIBMDBX_API void *mdbx_env_get_userctx(MDBX_env *env); -/* A callback function for most MDBX assert() failures, - * called before printing the message and aborting. - * - * [in] env An environment handle returned by mdbx_env_create(). - * [in] msg The assertion message, not including newline. */ -typedef void MDBX_assert_func(const MDBX_env *env, const char *msg, - const char *function, unsigned line); - -/* Set or reset the assert() callback of the environment. - * - * Does nothing if libmdbx was built with MDBX_DEBUG=0 or with NDEBUG, - * and will return MDBX_ENOSYS in such case. - * - * [in] env An environment handle returned by mdbx_env_create(). - * [in] func An MDBX_assert_func function, or 0. - * - * Returns A non-zero error value on failure and 0 on success. */ -LIBMDBX_API int mdbx_env_set_assert(MDBX_env *env, MDBX_assert_func *func); - /* Create a transaction for use with the environment. * * The transaction handle may be discarded using mdbx_txn_abort() @@ -2212,6 +2253,9 @@ typedef struct mdbx_canary { LIBMDBX_API int mdbx_canary_put(MDBX_txn *txn, const mdbx_canary *canary); LIBMDBX_API int mdbx_canary_get(MDBX_txn *txn, mdbx_canary *canary); +/* A callback function used to compare two keys in a database */ +typedef int(MDBX_cmp_func)(const MDBX_val *a, const MDBX_val *b); + /* Open a database in the environment. * * A database handle denotes the name and parameters of a database, @@ -3058,27 +3102,6 @@ LIBMDBX_API int mdbx_get_attr(MDBX_txn *txn, MDBX_dbi dbi, MDBX_val *key, MDBX_val *data, mdbx_attr_t *attrptr); #endif /* MDBX_NEXENTA_ATTRS */ -/*** DEBUG & LOGGING **********************************************************/ -/* FIXME: Complete description */ -#define MDBX_DBG_ASSERT 1 -#define MDBX_DBG_PRINT 2 -#define MDBX_DBG_TRACE 4 -#define MDBX_DBG_EXTRA 8 -#define MDBX_DBG_AUDIT 16 -#define MDBX_DBG_JITTER 32 -#define MDBX_DBG_DUMP 64 -#define MDBX_DBG_LEGACY_MULTIOPEN 128 - -typedef void MDBX_debug_func(int type, const char *function, int line, - const char *msg, va_list args); - -/* FIXME: Complete description */ -LIBMDBX_API int mdbx_setup_debug(int flags, MDBX_debug_func *logger); - -/* FIXME: Complete description */ -LIBMDBX_API char *mdbx_dkey(const MDBX_val *key, char *const buf, - const size_t bufsize); - /******************************************************************************/ /* LY: temporary workaround for Elbrus's memcmp() bug. */ #ifndef __GLIBC_PREREQ diff --git a/src/elements/core.c b/src/elements/core.c index 3bf6250f..a62ed717 100644 --- a/src/elements/core.c +++ b/src/elements/core.c @@ -812,7 +812,7 @@ __cold static int uniq_check(const mdbx_mmap_t *pending, MDBX_env **found) { if (err == MDBX_RESULT_TRUE) { err = uniq_poke(pending, &scan->me_lck_mmap, &salt); *found = scan; - mdbx_info("<< uniq-probe: found %p", *found); + mdbx_verbose("<< uniq-probe: found %p", *found); return MDBX_RESULT_FALSE; } if (unlikely(err != MDBX_SUCCESS)) { @@ -821,7 +821,7 @@ __cold static int uniq_check(const mdbx_mmap_t *pending, MDBX_env **found) { } } - mdbx_info("<< uniq-probe: unique"); + mdbx_verbose("<< uniq-probe: unique"); return MDBX_RESULT_TRUE; } @@ -1489,7 +1489,8 @@ static __inline void mdbx_dpl_clear(MDBX_DPL dl) { /*----------------------------------------------------------------------------*/ #ifndef MDBX_ALLOY -int mdbx_runtime_flags = MDBX_RUNTIME_FLAGS_INIT; +uint8_t mdbx_runtime_flags = MDBX_RUNTIME_FLAGS_INIT; +uint8_t mdbx_loglevel = MDBX_DEBUG; MDBX_debug_func *mdbx_debug_logger; #endif /* MDBX_ALLOY */ @@ -1750,13 +1751,13 @@ const char *mdbx_strerror_ANSI2OEM(int errnum) { static txnid_t mdbx_oomkick(MDBX_env *env, const txnid_t laggard); -void __cold mdbx_debug_log(int type, const char *function, int line, +void __cold mdbx_debug_log(int level, const char *function, int line, const char *fmt, ...) { va_list args; va_start(args, fmt); if (mdbx_debug_logger) - mdbx_debug_logger(type, function, line, fmt, args); + mdbx_debug_logger(level, function, line, fmt, args); else { #if defined(_WIN32) || defined(_WIN64) if (IsDebuggerPresent()) { @@ -1794,7 +1795,8 @@ void __cold mdbx_debug_log(int type, const char *function, int line, } /* Dump a key in ascii or hexadecimal. */ -char *mdbx_dkey(const MDBX_val *key, char *const buf, const size_t bufsize) { +char *mdbx_dump_val(const MDBX_val *key, char *const buf, + const size_t bufsize) { if (!key) return ""; if (!buf || bufsize < 4) @@ -1835,7 +1837,9 @@ char *mdbx_dkey(const MDBX_val *key, char *const buf, const size_t bufsize) { return buf; } -#if 0 /* LY: debug stuff */ +/*------------------------------------------------------------------------------ + LY: debug stuff */ + static const char *mdbx_leafnode_type(MDBX_node *n) { static char *const tp[2][2] = {{"", ": DB"}, {": sub-page", ": sub-DB"}}; return F_ISSET(n->mn_flags, F_BIGDATA) ? ": overflow page" @@ -1844,7 +1848,7 @@ static const char *mdbx_leafnode_type(MDBX_node *n) { } /* Display all the keys in the page. */ -static void mdbx_page_list(MDBX_page *mp) { +static __maybe_unused void mdbx_page_list(MDBX_page *mp) { pgno_t pgno = mp->mp_pgno; const char *type, *state = IS_DIRTY(mp) ? ", dirty" : ""; MDBX_node *node; @@ -1870,55 +1874,55 @@ static void mdbx_page_list(MDBX_page *mp) { type = "Leaf2 sub-page"; break; case P_OVERFLOW: - mdbx_print("Overflow page %" PRIu64 " pages %u%s\n", pgno, mp->mp_pages, - state); + mdbx_verbose("Overflow page %" PRIaPGNO " pages %u%s\n", pgno, mp->mp_pages, + state); return; case P_META: - mdbx_print("Meta-page %" PRIaPGNO " txnid %" PRIu64 "\n", pgno, - ((MDBX_meta *)PAGEDATA(mp))->mm_txnid_a.inconsistent); + mdbx_verbose("Meta-page %" PRIaPGNO " txnid %" PRIu64 "\n", pgno, + ((MDBX_meta *)PAGEDATA(mp))->mm_txnid_a.inconsistent); return; default: - mdbx_print("Bad page %" PRIu64 " flags 0x%X\n", pgno, mp->mp_flags); + mdbx_verbose("Bad page %" PRIaPGNO " flags 0x%X\n", pgno, mp->mp_flags); return; } nkeys = NUMKEYS(mp); - mdbx_print("%s %" PRIu64 " numkeys %u%s\n", type, pgno, nkeys, state); + mdbx_verbose("%s %" PRIaPGNO " numkeys %u%s\n", type, pgno, nkeys, state); for (i = 0; i < nkeys; i++) { if (IS_LEAF2(mp)) { /* LEAF2 pages have no mp_ptrs[] or node headers */ key.iov_len = nsize = mp->mp_leaf2_ksize; key.iov_base = LEAF2KEY(mp, i, nsize); total += nsize; - mdbx_print("key %u: nsize %u, %s\n", i, nsize, DKEY(&key)); + mdbx_verbose("key %u: nsize %u, %s\n", i, nsize, DKEY(&key)); continue; } node = NODEPTR(mp, i); key.iov_len = node->mn_ksize; key.iov_base = node->mn_data; - nsize = NODESIZE + key.iov_len; + nsize = (unsigned)(NODESIZE + key.iov_len); if (IS_BRANCH(mp)) { - mdbx_print("key %u: page %" PRIu64 ", %s\n", i, NODEPGNO(node), - DKEY(&key)); + mdbx_verbose("key %u: page %" PRIaPGNO ", %s\n", i, NODEPGNO(node), + DKEY(&key)); total += nsize; } else { if (F_ISSET(node->mn_flags, F_BIGDATA)) nsize += sizeof(pgno_t); else - nsize += NODEDSZ(node); + nsize += (unsigned)NODEDSZ(node); total += nsize; nsize += sizeof(indx_t); - mdbx_print("key %u: nsize %u, %s%s\n", i, nsize, DKEY(&key), - mdbx_leafnode_type(node)); + mdbx_verbose("key %u: nsize %u, %s%s\n", i, nsize, DKEY(&key), + mdbx_leafnode_type(node)); } total = EVEN(total); } - mdbx_print("Total: header %u + contents %u + unused %u\n", - IS_LEAF2(mp) ? PAGEHDRSZ : PAGEHDRSZ + mp->mp_lower, total, - SIZELEFT(mp)); + mdbx_verbose("Total: header %u + contents %u + unused %u\n", + IS_LEAF2(mp) ? PAGEHDRSZ : PAGEHDRSZ + mp->mp_lower, total, + SIZELEFT(mp)); } -static void mdbx_cursor_chk(MDBX_cursor *mc) { +static __maybe_unused void mdbx_cursor_chk(MDBX_cursor *mc) { unsigned i; MDBX_node *node; MDBX_page *mp; @@ -1929,19 +1933,20 @@ static void mdbx_cursor_chk(MDBX_cursor *mc) { mp = mc->mc_pg[i]; node = NODEPTR(mp, mc->mc_ki[i]); if (unlikely(NODEPGNO(node) != mc->mc_pg[i + 1]->mp_pgno)) - mdbx_print("oops!\n"); + mdbx_verbose("oops!\n"); } if (unlikely(mc->mc_ki[i] >= NUMKEYS(mc->mc_pg[i]))) - mdbx_print("ack!\n"); + mdbx_verbose("ack!\n"); if (XCURSOR_INITED(mc)) { node = NODEPTR(mc->mc_pg[mc->mc_top], mc->mc_ki[mc->mc_top]); if (((node->mn_flags & (F_DUPDATA | F_SUBDATA)) == F_DUPDATA) && mc->mc_xcursor->mx_cursor.mc_pg[0] != NODEDATA(node)) { - mdbx_print("blah!\n"); + mdbx_verbose("blah!\n"); } } } -#endif /* 0 */ + +/*----------------------------------------------------------------------------*/ int mdbx_cmp(MDBX_txn *txn, MDBX_dbi dbi, const MDBX_val *a, const MDBX_val *b) { @@ -2080,8 +2085,8 @@ static __must_check_result int mdbx_refund_loose(MDBX_txn *txn) { link = &NEXT_LOOSE_PAGE(*link); } else { *link = NEXT_LOOSE_PAGE(mp); - mdbx_info("refund loose-page: %" PRIaPGNO " -> %" PRIaPGNO, - txn->mt_next_pgno, mp->mp_pgno); + mdbx_verbose("refund loose-page: %" PRIaPGNO " -> %" PRIaPGNO, + txn->mt_next_pgno, mp->mp_pgno); txn->mt_next_pgno = mp->mp_pgno; if (txn->mt_rw_dirtylist) { MDBX_page *dp = mdbx_dpl_remove(txn->mt_rw_dirtylist, mp->mp_pgno); @@ -2659,10 +2664,10 @@ __cold static int mdbx_mapresize(MDBX_env *env, const pgno_t size_pgno, const size_t limit_bytes = pgno_align2os_bytes(env, limit_pgno); const size_t size_bytes = pgno_align2os_bytes(env, size_pgno); - mdbx_info("resize datafile/mapping: " - "present %" PRIuPTR " -> %" PRIuPTR ", " - "limit %" PRIuPTR " -> %" PRIuPTR, - env->me_dbgeo.now, size_bytes, env->me_dbgeo.upper, limit_bytes); + mdbx_verbose("resize datafile/mapping: " + "present %" PRIuPTR " -> %" PRIuPTR ", " + "limit %" PRIuPTR " -> %" PRIuPTR, + env->me_dbgeo.now, size_bytes, env->me_dbgeo.upper, limit_bytes); mdbx_assert(env, limit_bytes >= size_bytes); mdbx_assert(env, bytes2pgno(env, size_bytes) == size_pgno); @@ -2990,7 +2995,7 @@ static int mdbx_page_alloc(MDBX_cursor *mc, unsigned num, MDBX_page **mp, } env->me_last_reclaimed = last; - if (mdbx_debug_enabled(MDBX_DBG_EXTRA)) { + if (mdbx_log_enabled(MDBX_LOG_EXTRA)) { mdbx_debug_extra("PNL read txn %" PRIaTXN " root %" PRIaPGNO " num %u, PNL", last, txn->mt_dbs[FREE_DBI].md_root, repg_pos); @@ -3035,8 +3040,9 @@ static int mdbx_page_alloc(MDBX_cursor *mc, unsigned num, MDBX_page **mp, *move = *higest; #endif /* MDBX_PNL sort-order */ MDBX_PNL_SIZE(repg_list) = repg_len; - mdbx_info("refunded %" PRIaPGNO " pages: %" PRIaPGNO " -> %" PRIaPGNO, - tail - txn->mt_next_pgno, tail, txn->mt_next_pgno); + mdbx_verbose("refunded %" PRIaPGNO " pages: %" PRIaPGNO + " -> %" PRIaPGNO, + tail - txn->mt_next_pgno, tail, txn->mt_next_pgno); txn->mt_next_pgno = tail; mdbx_tassert(txn, mdbx_pnl_check(env->me_reclaimed_pglist, true)); } @@ -3130,8 +3136,9 @@ static int mdbx_page_alloc(MDBX_cursor *mc, unsigned num, MDBX_page **mp, aligned = head->mm_geo.upper; mdbx_assert(env, aligned > txn->mt_end_pgno); - mdbx_info("try growth datafile to %" PRIaPGNO " pages (+%" PRIaPGNO ")", - aligned, aligned - txn->mt_end_pgno); + mdbx_verbose("try growth datafile to %" PRIaPGNO " pages (+%" PRIaPGNO + ")", + aligned, aligned - txn->mt_end_pgno); rc = mdbx_mapresize(env, aligned, head->mm_geo.upper); if (rc == MDBX_SUCCESS) { mdbx_tassert(env->me_txn, txn->mt_end_pgno >= next); @@ -4724,7 +4731,7 @@ retry: for (pgno_t *move = begin; higest < end; ++move, ++higest) *move = *higest; #endif /* MDBX_PNL sort-order */ - mdbx_info( + mdbx_verbose( "%s.refunded %" PRIaPGNO " pages: %" PRIaPGNO " -> %" PRIaPGNO, dbg_prefix_mode, txn->mt_next_pgno - tail, tail, txn->mt_next_pgno); txn->mt_next_pgno = tail; @@ -4767,7 +4774,7 @@ retry: mdbx_trace("%s.put-retired #%u @ %" PRIaTXN, dbg_prefix_mode, retired_stored, txn->mt_txnid); - if (mdbx_debug_enabled(MDBX_DBG_EXTRA)) { + if (mdbx_log_enabled(MDBX_LOG_EXTRA)) { unsigned i = retired_stored; mdbx_debug_extra("PNL write txn %" PRIaTXN " root %" PRIaPGNO " num %u, PNL", @@ -5619,7 +5626,7 @@ static int __cold mdbx_read_header(MDBX_env *env, MDBX_meta *meta, if (memcmp(&page, &again, sizeof(page)) == 0 || --retryleft == 0) break; - mdbx_info("meta[%u] was updated, re-read it", meta_number); + mdbx_verbose("meta[%u] was updated, re-read it", meta_number); } if (page.mp_meta.mm_magic_and_version != MDBX_DATA_MAGIC && @@ -5660,8 +5667,8 @@ static int __cold mdbx_read_header(MDBX_env *env, MDBX_meta *meta, if (meta_number == 0 && guess_pagesize != page.mp_meta.mm_psize) { meta->mm_psize = page.mp_meta.mm_psize; - mdbx_info("meta[%u] took pagesize %u", meta_number, - page.mp_meta.mm_psize); + mdbx_verbose("meta[%u] took pagesize %u", meta_number, + page.mp_meta.mm_psize); } if (safe64_read(&page.mp_meta.mm_txnid_a) != @@ -5836,7 +5843,7 @@ static int __cold mdbx_read_header(MDBX_env *env, MDBX_meta *meta, *meta = page.mp_meta; if (META_IS_WEAK(meta)) loop_limit += 1; /* LY: should re-read to hush race with update */ - mdbx_info("latch meta[%u]", meta_number); + mdbx_verbose("latch meta[%u]", meta_number); } } @@ -6167,8 +6174,8 @@ static int mdbx_sync_locked(MDBX_env *env, unsigned flags, /* LY: shrink datafile if needed */ if (unlikely(shrink)) { - mdbx_info("shrink to %" PRIaPGNO " pages (-%" PRIaPGNO ")", - pending->mm_geo.now, shrink); + mdbx_verbose("shrink to %" PRIaPGNO " pages (-%" PRIaPGNO ")", + pending->mm_geo.now, shrink); rc = mdbx_mapresize(env, pending->mm_geo.now, pending->mm_geo.upper); if (MDBX_IS_ERROR(rc)) goto fail; @@ -6302,9 +6309,9 @@ static int __cold mdbx_env_map(MDBX_env *env, const int is_exclusive, #if defined(MADV_DODUMP) && defined(MADV_DONTDUMP) const size_t meta_length = pgno2bytes(env, NUM_METAS); (void)madvise(env->me_map, meta_length, MADV_DODUMP); - if ((env->me_flags & MDBX_PAGEPERTURB) == 0) - (void)madvise(env->me_map + meta_length, env->me_mapsize - meta_length, - MADV_DONTDUMP); + (void)madvise(env->me_map + meta_length, env->me_mapsize - meta_length, + (mdbx_runtime_flags & MDBX_DBG_DUMP) ? MADV_DODUMP + : MADV_DONTDUMP); #endif if (is_exclusive && (env->me_flags & MDBX_WRITEMAP) != 0) { @@ -6787,13 +6794,13 @@ static int __cold mdbx_setup_dxb(MDBX_env *env, const int lck_rc) { #endif } - mdbx_info("header: root %" PRIaPGNO "/%" PRIaPGNO ", geo %" PRIaPGNO - "/%" PRIaPGNO "-%" PRIaPGNO "/%" PRIaPGNO - " +%u -%u, txn_id %" PRIaTXN ", %s", - meta.mm_dbs[MAIN_DBI].md_root, meta.mm_dbs[FREE_DBI].md_root, - meta.mm_geo.lower, meta.mm_geo.next, meta.mm_geo.now, - meta.mm_geo.upper, meta.mm_geo.grow, meta.mm_geo.shrink, - meta.mm_txnid_a.inconsistent, mdbx_durable_str(&meta)); + mdbx_verbose("header: root %" PRIaPGNO "/%" PRIaPGNO ", geo %" PRIaPGNO + "/%" PRIaPGNO "-%" PRIaPGNO "/%" PRIaPGNO + " +%u -%u, txn_id %" PRIaTXN ", %s", + meta.mm_dbs[MAIN_DBI].md_root, meta.mm_dbs[FREE_DBI].md_root, + meta.mm_geo.lower, meta.mm_geo.next, meta.mm_geo.now, + meta.mm_geo.upper, meta.mm_geo.grow, meta.mm_geo.shrink, + meta.mm_txnid_a.inconsistent, mdbx_durable_str(&meta)); mdbx_setup_pagesize(env, meta.mm_psize); const size_t used_bytes = pgno2bytes(env, meta.mm_geo.next); @@ -6850,13 +6857,13 @@ static int __cold mdbx_setup_dxb(MDBX_env *env, const int lck_rc) { meta.mm_geo.grow = (uint16_t)bytes2pgno(env, env->me_dbgeo.grow); meta.mm_geo.shrink = (uint16_t)bytes2pgno(env, env->me_dbgeo.shrink); - mdbx_info("amended: root %" PRIaPGNO "/%" PRIaPGNO ", geo %" PRIaPGNO - "/%" PRIaPGNO "-%" PRIaPGNO "/%" PRIaPGNO - " +%u -%u, txn_id %" PRIaTXN ", %s", - meta.mm_dbs[MAIN_DBI].md_root, meta.mm_dbs[FREE_DBI].md_root, - meta.mm_geo.lower, meta.mm_geo.next, meta.mm_geo.now, - meta.mm_geo.upper, meta.mm_geo.grow, meta.mm_geo.shrink, - meta.mm_txnid_a.inconsistent, mdbx_durable_str(&meta)); + mdbx_verbose("amended: root %" PRIaPGNO "/%" PRIaPGNO ", geo %" PRIaPGNO + "/%" PRIaPGNO "-%" PRIaPGNO "/%" PRIaPGNO + " +%u -%u, txn_id %" PRIaTXN ", %s", + meta.mm_dbs[MAIN_DBI].md_root, meta.mm_dbs[FREE_DBI].md_root, + meta.mm_geo.lower, meta.mm_geo.next, meta.mm_geo.now, + meta.mm_geo.upper, meta.mm_geo.grow, meta.mm_geo.shrink, + meta.mm_txnid_a.inconsistent, mdbx_durable_str(&meta)); } mdbx_ensure(env, meta.mm_geo.now >= meta.mm_geo.next); } else { @@ -6874,12 +6881,12 @@ static int __cold mdbx_setup_dxb(MDBX_env *env, const int lck_rc) { mdbx_ensure(env, expected_bytes >= used_bytes); if (filesize_before_mmap != expected_bytes) { if (lck_rc != /* lck exclusive */ MDBX_RESULT_TRUE) { - mdbx_info("filesize mismatch (expect %" PRIuPTR "/%" PRIaPGNO - ", have %" PRIu64 "/%" PRIaPGNO "), " - "assume collision in non-exclusive mode", - expected_bytes, bytes2pgno(env, expected_bytes), - filesize_before_mmap, - bytes2pgno(env, (size_t)filesize_before_mmap)); + mdbx_verbose("filesize mismatch (expect %" PRIuPTR "/%" PRIaPGNO + ", have %" PRIu64 "/%" PRIaPGNO "), " + "assume collision in non-exclusive mode", + expected_bytes, bytes2pgno(env, expected_bytes), + filesize_before_mmap, + bytes2pgno(env, (size_t)filesize_before_mmap)); } else { mdbx_notice("filesize mismatch (expect %" PRIuSIZE "/%" PRIaPGNO ", have %" PRIu64 "/%" PRIaPGNO ")", @@ -6901,8 +6908,9 @@ static int __cold mdbx_setup_dxb(MDBX_env *env, const int lck_rc) { } mdbx_notice("ignore filesize mismatch in readonly-mode"); } else { - mdbx_info("resize datafile to %" PRIuSIZE " bytes, %" PRIaPGNO " pages", - expected_bytes, bytes2pgno(env, expected_bytes)); + mdbx_verbose("resize datafile to %" PRIuSIZE " bytes, %" PRIaPGNO + " pages", + expected_bytes, bytes2pgno(env, expected_bytes)); err = mdbx_ftruncate(env->me_fd, expected_bytes); if (unlikely(err != MDBX_SUCCESS)) { mdbx_error("error %d, while resize datafile to %" PRIuSIZE @@ -6999,7 +7007,7 @@ static int __cold mdbx_setup_dxb(MDBX_env *env, const int lck_rc) { /* LY: assume just have a collision with other running process, * or someone make a weak checkpoint */ - mdbx_info("assume collision or online weak checkpoint"); + mdbx_verbose("assume collision or online weak checkpoint"); break; } @@ -7012,50 +7020,51 @@ static int __cold mdbx_setup_dxb(MDBX_env *env, const int lck_rc) { return err; if (filesize_after_mmap != expected_bytes) { if (filesize_after_mmap != filesize_before_mmap) - mdbx_info("datafile resized by system to %" PRIu64 " bytes", - filesize_after_mmap); + mdbx_verbose("datafile resized by system to %" PRIu64 " bytes", + filesize_after_mmap); if (filesize_after_mmap % env->me_os_psize || filesize_after_mmap > env->me_dbgeo.upper || filesize_after_mmap < used_bytes) { - mdbx_info("unacceptable/unexpected datafile size %" PRIu64, - filesize_after_mmap); + mdbx_verbose("unacceptable/unexpected datafile size %" PRIu64, + filesize_after_mmap); return MDBX_PROBLEM; } if ((env->me_flags & MDBX_RDONLY) == 0) { meta.mm_geo.now = bytes2pgno(env, env->me_dbgeo.now = (size_t)filesize_after_mmap); - mdbx_info("update meta-geo to filesize %" PRIuPTR " bytes, %" PRIaPGNO - " pages", - env->me_dbgeo.now, meta.mm_geo.now); + mdbx_verbose("update meta-geo to filesize %" PRIuPTR + " bytes, %" PRIaPGNO " pages", + env->me_dbgeo.now, meta.mm_geo.now); } } if (memcmp(&meta.mm_geo, &head->mm_geo, sizeof(meta.mm_geo))) { const txnid_t txnid = mdbx_meta_txnid_stable(env, head); - mdbx_info("updating meta.geo: " - "from l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO - "/s%u-g%u (txn#%" PRIaTXN "), " - "to l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO - "/s%u-g%u (txn#%" PRIaTXN ")", - head->mm_geo.lower, head->mm_geo.now, head->mm_geo.upper, - head->mm_geo.shrink, head->mm_geo.grow, txnid, - meta.mm_geo.lower, meta.mm_geo.now, meta.mm_geo.upper, - meta.mm_geo.shrink, meta.mm_geo.grow, txnid + 1); + mdbx_verbose("updating meta.geo: " + "from l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO + "/s%u-g%u (txn#%" PRIaTXN "), " + "to l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO + "/s%u-g%u (txn#%" PRIaTXN ")", + head->mm_geo.lower, head->mm_geo.now, head->mm_geo.upper, + head->mm_geo.shrink, head->mm_geo.grow, txnid, + meta.mm_geo.lower, meta.mm_geo.now, meta.mm_geo.upper, + meta.mm_geo.shrink, meta.mm_geo.grow, txnid + 1); mdbx_ensure(env, mdbx_meta_eq(env, &meta, head)); mdbx_meta_set_txnid(env, &meta, txnid + 1); *env->me_unsynced_pages += 1; err = mdbx_sync_locked(env, env->me_flags | MDBX_SHRINK_ALLOWED, &meta); if (err) { - mdbx_info("error %d, while updating meta.geo: " - "from l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO - "/s%u-g%u (txn#%" PRIaTXN "), " - "to l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO - "/s%u-g%u (txn#%" PRIaTXN ")", - err, head->mm_geo.lower, head->mm_geo.now, head->mm_geo.upper, - head->mm_geo.shrink, head->mm_geo.grow, txnid, - meta.mm_geo.lower, meta.mm_geo.now, meta.mm_geo.upper, - meta.mm_geo.shrink, meta.mm_geo.grow, txnid + 1); + mdbx_verbose("error %d, while updating meta.geo: " + "from l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO + "/s%u-g%u (txn#%" PRIaTXN "), " + "to l%" PRIaPGNO "-n%" PRIaPGNO "-u%" PRIaPGNO + "/s%u-g%u (txn#%" PRIaTXN ")", + err, head->mm_geo.lower, head->mm_geo.now, + head->mm_geo.upper, head->mm_geo.shrink, head->mm_geo.grow, + txnid, meta.mm_geo.lower, meta.mm_geo.now, + meta.mm_geo.upper, meta.mm_geo.shrink, meta.mm_geo.grow, + txnid + 1); return err; } } @@ -10596,7 +10605,7 @@ static int mdbx_update_key(MDBX_cursor *mc, const MDBX_val *key) { k2.iov_base = NODEKEY(node); k2.iov_len = node->mn_ksize; mdbx_debug("update key %u (ofs %u) [%s] to [%s] on page %" PRIaPGNO, indx, - ptr, mdbx_dkey(&k2, kbuf2, sizeof(kbuf2)), DKEY(key), + ptr, mdbx_dump_val(&k2, kbuf2, sizeof(kbuf2)), DKEY(key), mp->mp_pgno); } @@ -13753,15 +13762,22 @@ int __cold mdbx_reader_check0(MDBX_env *env, int rdt_locked, int *dead) { return rc; } -int __cold mdbx_setup_debug(int flags, MDBX_debug_func *logger) { - const int rc = mdbx_runtime_flags; +int __cold mdbx_setup_debug(int loglevel, int flags, MDBX_debug_func *logger) { + const int rc = mdbx_runtime_flags | (mdbx_loglevel << 16); + +#if !MDBX_DEBUG + (void)loglevel; +#else + if (loglevel != -1) + mdbx_loglevel = (uint8_t)loglevel; +#endif + if (flags != -1) { #if !MDBX_DEBUG flags &= MDBX_DBG_DUMP | MDBX_DBG_LEGACY_MULTIOPEN; #else - flags &= MDBX_DBG_ASSERT | MDBX_DBG_PRINT | MDBX_DBG_TRACE | - MDBX_DBG_EXTRA | MDBX_DBG_AUDIT | MDBX_DBG_JITTER | MDBX_DBG_DUMP | - MDBX_DBG_LEGACY_MULTIOPEN; + flags &= MDBX_DBG_ASSERT | MDBX_DBG_AUDIT | MDBX_DBG_JITTER | + MDBX_DBG_DUMP | MDBX_DBG_LEGACY_MULTIOPEN; #endif #if defined(__linux__) || defined(__gnu_linux__) if ((mdbx_runtime_flags ^ flags) & MDBX_DBG_DUMP) { @@ -13793,7 +13809,7 @@ int __cold mdbx_setup_debug(int flags, MDBX_debug_func *logger) { } } #endif /* Linux */ - mdbx_runtime_flags = flags; + mdbx_runtime_flags = (uint8_t)flags; } if (-1 != (intptr_t)logger) diff --git a/src/elements/internals.h b/src/elements/internals.h index b02f3c13..1df5735e 100644 --- a/src/elements/internals.h +++ b/src/elements/internals.h @@ -987,12 +987,13 @@ typedef struct MDBX_ntxn { /* Debug and Logging stuff */ #define MDBX_RUNTIME_FLAGS_INIT \ - (MDBX_DBG_PRINT | ((MDBX_DEBUG) > 0) * MDBX_DBG_ASSERT | \ - ((MDBX_DEBUG) > 1) * MDBX_DBG_AUDIT | ((MDBX_DEBUG) > 2) * MDBX_DBG_TRACE | \ - ((MDBX_DEBUG) > 3) * MDBX_DBG_EXTRA) + ((MDBX_DEBUG) > 0) * MDBX_DBG_ASSERT + ((MDBX_DEBUG) > 1) * MDBX_DBG_AUDIT #ifndef mdbx_runtime_flags /* avoid override from tools */ -MDBX_INTERNAL_VAR int mdbx_runtime_flags; +MDBX_INTERNAL_VAR uint8_t mdbx_runtime_flags; +#endif +#ifndef mdbx_runtime_flags /* avoid override from tools */ +MDBX_INTERNAL_VAR uint8_t mdbx_loglevel; #endif MDBX_INTERNAL_VAR MDBX_debug_func *mdbx_debug_logger; @@ -1008,100 +1009,99 @@ MDBX_INTERNAL_FUNC void mdbx_panic(const char *fmt, ...) __printf_args(1, 2); #define mdbx_audit_enabled() unlikely(mdbx_runtime_flags &MDBX_DBG_AUDIT) -#define mdbx_debug_enabled(type) \ - unlikely(mdbx_runtime_flags &(type & (MDBX_DBG_TRACE | MDBX_DBG_EXTRA))) - +#ifdef MDBX_LOGLEVEL_BUILD +#define mdbx_log_enabled(msg) \ + (msg <= MDBX_LOGLEVEL_BUILD && unlikely(msg <= mdbx_loglevel)) #else -#define mdbx_debug_enabled(type) (0) +#define mdbx_log_enabled(msg) unlikely(msg <= mdbx_loglevel) +#endif /* MDBX_LOGLEVEL_BUILD */ + +#else /* MDBX_DEBUG */ + #define mdbx_audit_enabled() (0) + #if !defined(NDEBUG) || defined(MDBX_FORCE_ASSERT) #define mdbx_assert_enabled() (1) #else #define mdbx_assert_enabled() (0) #endif /* NDEBUG */ + +#ifdef MDBX_LOGLEVEL_BUILD +#define mdbx_log_enabled(msg) (msg <= MDBX_LOGLEVEL_BUILD) +#else +#define mdbx_log_enabled(msg) (0) +#endif /* MDBX_LOGLEVEL_BUILD */ + #endif /* MDBX_DEBUG */ MDBX_INTERNAL_FUNC void mdbx_assert_fail(const MDBX_env *env, const char *msg, const char *func, int line); -#define mdbx_print(fmt, ...) \ - mdbx_debug_log(MDBX_DBG_PRINT, NULL, 0, fmt, ##__VA_ARGS__) - -#define mdbx_trace(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE)) \ - mdbx_debug_log(MDBX_DBG_TRACE, __FUNCTION__, __LINE__, fmt "\n", \ - ##__VA_ARGS__); \ - } while (0) - -#define mdbx_verbose(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE /* FIXME */)) \ - mdbx_debug_log(MDBX_DBG_TRACE /* FIXME */, __FUNCTION__, __LINE__, \ - fmt "\n", ##__VA_ARGS__); \ - } while (0) - -#define mdbx_info(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE /* FIXME */)) \ - mdbx_debug_log(MDBX_DBG_TRACE /* FIXME */, __FUNCTION__, __LINE__, \ - fmt "\n", ##__VA_ARGS__); \ - } while (0) - -#define mdbx_notice(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE /* FIXME */)) \ - mdbx_debug_log(MDBX_DBG_TRACE /* FIXME */, __FUNCTION__, __LINE__, \ - fmt "\n", ##__VA_ARGS__); \ - } while (0) - -#define mdbx_warning(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE /* FIXME */)) \ - mdbx_debug_log(MDBX_DBG_TRACE /* FIXME */, __FUNCTION__, __LINE__, \ - fmt "\n", ##__VA_ARGS__); \ - } while (0) - -#define mdbx_error(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE /* FIXME */)) \ - mdbx_debug_log(MDBX_DBG_TRACE /* FIXME */, __FUNCTION__, __LINE__, \ - fmt "\n", ##__VA_ARGS__); \ - } while (0) - -#define mdbx_fatal(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE /* FIXME */)) \ - mdbx_debug_log(MDBX_DBG_TRACE /* FIXME */, __FUNCTION__, __LINE__, \ - fmt "\n", ##__VA_ARGS__); \ - } while (0) - -#define mdbx_debug(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE)) \ - mdbx_debug_log(MDBX_DBG_TRACE, __FUNCTION__, __LINE__, fmt "\n", \ - ##__VA_ARGS__); \ - } while (0) - -#define mdbx_debug_print(fmt, ...) \ - do { \ - if (mdbx_debug_enabled(MDBX_DBG_TRACE)) \ - mdbx_debug_log(MDBX_DBG_TRACE, NULL, 0, fmt, ##__VA_ARGS__); \ - } while (0) - #define mdbx_debug_extra(fmt, ...) \ do { \ - if (mdbx_debug_enabled(MDBX_DBG_EXTRA)) \ - mdbx_debug_log(MDBX_DBG_EXTRA, __FUNCTION__, __LINE__, fmt, \ + if (mdbx_log_enabled(MDBX_LOG_EXTRA)) \ + mdbx_debug_log(MDBX_LOG_EXTRA, __FUNCTION__, __LINE__, fmt, \ ##__VA_ARGS__); \ } while (0) #define mdbx_debug_extra_print(fmt, ...) \ do { \ - if (mdbx_debug_enabled(MDBX_DBG_EXTRA)) \ - mdbx_debug_log(MDBX_DBG_EXTRA, NULL, 0, fmt, ##__VA_ARGS__); \ + if (mdbx_log_enabled(MDBX_LOG_EXTRA)) \ + mdbx_debug_log(MDBX_LOG_EXTRA, NULL, 0, fmt, ##__VA_ARGS__); \ } while (0) +#define mdbx_trace(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_TRACE)) \ + mdbx_debug_log(MDBX_LOG_TRACE, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); \ + } while (0) + +#define mdbx_debug(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_DEBUG)) \ + mdbx_debug_log(MDBX_LOG_DEBUG, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); \ + } while (0) + +#define mdbx_debug_print(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_DEBUG)) \ + mdbx_debug_log(MDBX_LOG_DEBUG, NULL, 0, fmt, ##__VA_ARGS__); \ + } while (0) + +#define mdbx_verbose(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_VERBOSE)) \ + mdbx_debug_log(MDBX_LOG_VERBOSE, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); \ + } while (0) + +#define mdbx_notice(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_NOTICE)) \ + mdbx_debug_log(MDBX_LOG_NOTICE, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); \ + } while (0) + +#define mdbx_warning(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_WARN)) \ + mdbx_debug_log(MDBX_LOG_WARN, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); \ + } while (0) + +#define mdbx_error(fmt, ...) \ + do { \ + if (mdbx_log_enabled(MDBX_LOG_ERROR)) \ + mdbx_debug_log(MDBX_LOG_ERROR, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); \ + } while (0) + +#define mdbx_fatal(fmt, ...) \ + mdbx_debug_log(MDBX_LOG_FATAL, __FUNCTION__, __LINE__, fmt "\n", \ + ##__VA_ARGS__); + #define mdbx_ensure_msg(env, expr, msg) \ do { \ if (unlikely(!(expr))) \ @@ -1156,9 +1156,9 @@ MDBX_INTERNAL_FUNC void mdbx_rthc_thread_dtor(void *ptr); #if MDBX_DEBUG #define DKBUF char _kbuf[DKBUF_MAXKEYSIZE * 4 + 2] -#define DKEY(x) mdbx_dkey(x, _kbuf, DKBUF_MAXKEYSIZE * 2 + 1) +#define DKEY(x) mdbx_dump_val(x, _kbuf, DKBUF_MAXKEYSIZE * 2 + 1) #define DVAL(x) \ - mdbx_dkey(x, _kbuf + DKBUF_MAXKEYSIZE * 2 + 1, DKBUF_MAXKEYSIZE * 2 + 1) + mdbx_dump_val(x, _kbuf + DKBUF_MAXKEYSIZE * 2 + 1, DKBUF_MAXKEYSIZE * 2 + 1) #else #define DKBUF ((void)(0)) #define DKEY(x) ("-") diff --git a/src/elements/lck-posix.c b/src/elements/lck-posix.c index 472c3a5b..2358b6b9 100644 --- a/src/elements/lck-posix.c +++ b/src/elements/lck-posix.c @@ -318,7 +318,7 @@ MDBX_INTERNAL_FUNC int __cold mdbx_lck_destroy(MDBX_env *env, lck_op(env->me_lfd, op_setlk, F_WRLCK, 0, OFF_T_MAX) == 0 && lck_op(env->me_fd, op_setlk, (env->me_flags & MDBX_RDONLY) ? F_RDLCK : F_WRLCK, 0, OFF_T_MAX)) { - mdbx_info("%s: got exclusive, drown mutexes", mdbx_func_); + mdbx_verbose("%s: got exclusive, drown mutexes", mdbx_func_); rc = pthread_mutex_destroy(&env->me_lck->mti_rmutex); if (rc == 0) rc = pthread_mutex_destroy(&env->me_lck->mti_wmutex); diff --git a/src/elements/osal.c b/src/elements/osal.c index 51af33a1..70357da0 100644 --- a/src/elements/osal.c +++ b/src/elements/osal.c @@ -211,7 +211,7 @@ MDBX_INTERNAL_FUNC void __cold mdbx_assert_fail(const MDBX_env *env, #endif /* MDBX_DEBUG */ if (mdbx_debug_logger) - mdbx_debug_log(MDBX_DBG_ASSERT, func, line, "assert: %s\n", msg); + mdbx_debug_log(MDBX_LOG_FATAL, func, line, "assert: %s\n", msg); else { #if defined(_WIN32) || defined(_WIN64) char *message = nullptr; diff --git a/test/keygen.cc b/test/keygen.cc index 9b283a12..e1561420 100644 --- a/test/keygen.cc +++ b/test/keygen.cc @@ -137,8 +137,8 @@ void __hot maker::pair(serial_t serial, const buffer &key, buffer &value, if (log_enabled(logging::trace)) { char dump_key[128], dump_value[128]; log_trace("keygen-pair: key %s, value %s", - mdbx_dkey(&key->value, dump_key, sizeof(dump_key)), - mdbx_dkey(&value->value, dump_value, sizeof(dump_value))); + mdbx_dump_val(&key->value, dump_key, sizeof(dump_key)), + mdbx_dump_val(&value->value, dump_value, sizeof(dump_value))); } } diff --git a/test/log.cc b/test/log.cc index 79544e11..4d7cb661 100644 --- a/test/log.cc +++ b/test/log.cc @@ -37,29 +37,18 @@ void __noreturn failure_perror(const char *what, int errnum) { //----------------------------------------------------------------------------- -static void mdbx_logger(int type, const char *function, int line, +static void mdbx_logger(int loglevel, const char *function, int line, const char *msg, va_list args) { - logging::loglevel level = logging::info; - if (type & MDBX_DBG_EXTRA) - level = logging::extra; - if (type & MDBX_DBG_TRACE) - level = logging::trace; - if (type & MDBX_DBG_PRINT) - level = logging::verbose; - if (!function) function = "unknown"; - if (type & MDBX_DBG_ASSERT) { - log_error("mdbx: assertion failure: %s, %d", function, line); - level = logging::failure; - } + + if (loglevel == MDBX_LOG_FATAL) + log_error("mdbx: fatal failure: %s, %d", function, line); if (logging::output( - level, + logging::loglevel(loglevel), strncmp(function, "mdbx_", 5) == 0 ? "%s: " : "mdbx: %s: ", function)) logging::feed_ap(msg, args); - if (type & MDBX_DBG_ASSERT) - abort(); } namespace logging { @@ -70,13 +59,8 @@ static loglevel level; static FILE *last; void setlevel(loglevel _level) { - level = (_level > error) ? failure : _level; - int mdbx_dbg_opts = MDBX_DBG_ASSERT | MDBX_DBG_JITTER | MDBX_DBG_DUMP; - if (level <= trace) - mdbx_dbg_opts |= MDBX_DBG_TRACE; - if (level <= verbose) - mdbx_dbg_opts |= MDBX_DBG_PRINT; - int rc = mdbx_setup_debug(mdbx_dbg_opts, mdbx_logger); + int rc = mdbx_setup_debug( + _level, MDBX_DBG_ASSERT | MDBX_DBG_JITTER | MDBX_DBG_DUMP, mdbx_logger); log_trace("set mdbx debug-opts: 0x%02x", rc); } @@ -95,8 +79,8 @@ const char *level2str(const loglevel alevel) { return "extra"; case trace: return "trace"; - case verbose: - return "verbose"; + case debug: + return "debug"; case info: return "info"; case notice: @@ -111,7 +95,7 @@ const char *level2str(const loglevel alevel) { } bool output(const loglevel priority, const char *format, ...) { - if (priority < level) + if (priority > level) return false; va_list ap; @@ -245,7 +229,7 @@ local_suffix::~local_suffix() { suffix.erase(trim_pos); } } // namespace logging void log_extra(const char *msg, ...) { - if (logging::extra >= logging::level) { + if (logging::extra <= logging::level) { va_list ap; va_start(ap, msg); logging::output(logging::extra, msg, ap); @@ -255,7 +239,7 @@ void log_extra(const char *msg, ...) { } void log_trace(const char *msg, ...) { - if (logging::trace >= logging::level) { + if (logging::trace <= logging::level) { va_list ap; va_start(ap, msg); logging::output(logging::trace, msg, ap); @@ -264,18 +248,18 @@ void log_trace(const char *msg, ...) { logging::last = nullptr; } -void log_verbose(const char *msg, ...) { - if (logging::verbose >= logging::level) { +void log_debug(const char *msg, ...) { + if (logging::debug <= logging::level) { va_list ap; va_start(ap, msg); - logging::output(logging::verbose, msg, ap); + logging::output(logging::debug, msg, ap); va_end(ap); } else logging::last = nullptr; } void log_info(const char *msg, ...) { - if (logging::info >= logging::level) { + if (logging::info <= logging::level) { va_list ap; va_start(ap, msg); logging::output(logging::info, msg, ap); @@ -285,7 +269,7 @@ void log_info(const char *msg, ...) { } void log_notice(const char *msg, ...) { - if (logging::notice >= logging::level) { + if (logging::notice <= logging::level) { va_list ap; va_start(ap, msg); logging::output(logging::notice, msg, ap); @@ -295,7 +279,7 @@ void log_notice(const char *msg, ...) { } void log_warning(const char *msg, ...) { - if (logging::warning >= logging::level) { + if (logging::warning <= logging::level) { va_list ap; va_start(ap, msg); logging::output(logging::warning, msg, ap); @@ -305,7 +289,7 @@ void log_warning(const char *msg, ...) { } void log_error(const char *msg, ...) { - if (logging::error >= logging::level) { + if (logging::error <= logging::level) { va_list ap; va_start(ap, msg); logging::output(logging::error, msg, ap); diff --git a/test/log.h b/test/log.h index 7d6b4012..4df145eb 100644 --- a/test/log.h +++ b/test/log.h @@ -24,14 +24,14 @@ const char *test_strerror(int errnum); namespace logging { enum loglevel { - extra, - trace, - verbose, - info, - notice, - warning, - error, - failure, + extra = MDBX_LOG_EXTRA, + trace = MDBX_LOG_TRACE, + debug = MDBX_LOG_DEBUG, + info = MDBX_LOG_VERBOSE, + notice = MDBX_LOG_NOTICE, + warning = MDBX_LOG_WARN, + error = MDBX_LOG_ERROR, + failure = MDBX_LOG_FATAL }; const char *level2str(const loglevel level); @@ -66,7 +66,7 @@ public: void __printf_args(1, 2) log_extra(const char *msg, ...); void __printf_args(1, 2) log_trace(const char *msg, ...); -void __printf_args(1, 2) log_verbose(const char *msg, ...); +void __printf_args(1, 2) log_debug(const char *msg, ...); void __printf_args(1, 2) log_info(const char *msg, ...); void __printf_args(1, 2) log_notice(const char *msg, ...); void __printf_args(1, 2) log_warning(const char *msg, ...); diff --git a/test/main.cc b/test/main.cc index 14520428..6b369ecd 100644 --- a/test/main.cc +++ b/test/main.cc @@ -28,7 +28,7 @@ void actor_params::set_defaults(const std::string &tmpdir) { #ifdef NDEBUG logging::info; #elif defined(_WIN32) || defined(_WIN64) - logging::verbose; + logging::debug; #else logging::trace; #endif diff --git a/test/test.cc b/test/test.cc index 02c76ef5..60f426c4 100644 --- a/test/test.cc +++ b/test/test.cc @@ -328,8 +328,8 @@ void testcase::report(size_t nops_done) { return; nops_completed += nops_done; - log_verbose("== complete +%" PRIuPTR " iteration, total %" PRIuPTR " done", - nops_done, nops_completed); + log_debug("== complete +%" PRIuPTR " iteration, total %" PRIuPTR " done", + nops_done, nops_completed); if (global::config::progress_indicator) kick_progress(true); @@ -464,7 +464,7 @@ MDBX_dbi testcase::db_table_open(bool create) { failure("snprintf(tablename): %d", rc); tablename = tablename_buf; } - log_verbose("use %s table", tablename ? tablename : "MAINDB"); + log_debug("use %s table", tablename ? tablename : "MAINDB"); MDBX_dbi handle = 0; int rc = mdbx_dbi_open(txn_guard.get(), tablename, diff --git a/test/ttl.cc b/test/ttl.cc index 0a948993..aad24467 100644 --- a/test/ttl.cc +++ b/test/ttl.cc @@ -92,9 +92,9 @@ bool testcase_ttl::run() { const unsigned window_width = edge2window(salt, window_max); unsigned head_count = edge2count(salt, count_max); - log_verbose("ttl: step #%zu (serial %" PRIu64 - ", window %u, count %u) salt %" PRIu64, - nops_completed, serial, window_width, head_count, salt); + log_debug("ttl: step #%zu (serial %" PRIu64 + ", window %u, count %u) salt %" PRIu64, + nops_completed, serial, window_width, head_count, salt); if (window_width) { while (fifo.size() > window_width) {