diff --git a/ChangeLog.md b/ChangeLog.md index 2395b116..bfa3eadb 100644 --- a/ChangeLog.md +++ b/ChangeLog.md @@ -12,6 +12,7 @@ TODO: Added features: - Provided package for [buildroot](https://buildroot.org/). - Added `mdbx_env_delete()` for deletion an environment files in a proper and multiprocess-safe way. + - Added `mdbx_txn_commit_ex()` with collecting latency information. Fixes: diff --git a/mdbx.h b/mdbx.h index 6ecc1f75..009b6de4 100644 --- a/mdbx.h +++ b/mdbx.h @@ -2921,6 +2921,38 @@ MDBX_NOTHROW_PURE_FUNCTION LIBMDBX_API int mdbx_txn_flags(const MDBX_txn *txn); MDBX_NOTHROW_PURE_FUNCTION LIBMDBX_API uint64_t mdbx_txn_id(const MDBX_txn *txn); +/** \brief Latency of commit stages in 1/65536 of seconds units. + * \warning This structure may be changed in future releases. + * \see mdbx_txn_commit_ex() */ +struct MDBX_commit_latency { + /** \brief Duration of preparation (commit child transactions, update + * sub-databases records and cursors destroying). */ + uint32_t preparation; + /** \brief Duration of GC/freeDB handling & updation. */ + uint32_t gc; + /** \brief Duration of internal audit if enabled. */ + uint32_t audit; + /** \brief Duration of writing dirty/modified data pages. */ + uint32_t write; + /** \brief Duration of syncing written data to the dist/storage. */ + uint32_t sync; + /** \brief Duration of transaction ending (releasing resources). */ + uint32_t ending; + /** \brief The total duration of a commit. */ + uint32_t whole; +}; +#ifndef __cplusplus +/** \ingroup c_statinfo */ +typedef struct MDBX_commit_latency MDBX_commit_latency; +#endif + +/** \brief Commit all the operations of a transaction into the database and + * collect latency information. + * \see mdbx_txn_commit() + * \ingroup c_statinfo + * \warning This function may be changed in future releases. */ +LIBMDBX_API int mdbx_txn_commit_ex(MDBX_txn *txn, MDBX_commit_latency *latency); + /** \brief Commit all the operations of a transaction into the database. * \ingroup c_transactions * @@ -2958,7 +2990,9 @@ mdbx_txn_id(const MDBX_txn *txn); * \retval MDBX_ENOSPC No more disk space. * \retval MDBX_EIO A system-level I/O error occurred. * \retval MDBX_ENOMEM Out of memory. */ -LIBMDBX_API int mdbx_txn_commit(MDBX_txn *txn); +LIBMDBX_INLINE_API(int, mdbx_txn_commit, (MDBX_txn * txn)) { + return mdbx_txn_commit_ex(txn, NULL); +} /** \brief Abandon all the operations of the transaction instead of saving them. * \ingroup c_transactions diff --git a/src/core.c b/src/core.c index f4fac622..f7bfef63 100644 --- a/src/core.c +++ b/src/core.c @@ -8025,12 +8025,18 @@ static __always_inline bool mdbx_txn_dbi_exists(MDBX_txn *txn, MDBX_dbi dbi, return mdbx_txn_import_dbi(txn, dbi); } -int mdbx_txn_commit(MDBX_txn *txn) { +int mdbx_txn_commit(MDBX_txn *txn) { return __inline_mdbx_txn_commit(txn); } + +int mdbx_txn_commit_ex(MDBX_txn *txn, MDBX_commit_latency *latency) { STATIC_ASSERT(MDBX_TXN_FINISHED == MDBX_TXN_BLOCKED - MDBX_TXN_HAS_CHILD - MDBX_TXN_ERROR); + const uint64_t ts_0 = latency ? mdbx_osal_monotime() : 0; + uint64_t ts_1 = 0, ts_2 = 0, ts_3 = 0, ts_4 = 0; + uint32_t audit_duration = 0; + int rc = check_txn(txn, MDBX_TXN_FINISHED); if (unlikely(rc != MDBX_SUCCESS)) - return rc; + goto provide_latency; if (unlikely(txn->mt_flags & MDBX_TXN_ERROR)) { rc = MDBX_RESULT_TRUE; @@ -8041,7 +8047,8 @@ int mdbx_txn_commit(MDBX_txn *txn) { #if MDBX_ENV_CHECKPID if (unlikely(env->me_pid != mdbx_getpid())) { env->me_flags |= MDBX_FATAL_ERROR; - return MDBX_PANIC; + rc = MDBX_PANIC; + goto provide_latency; } #endif /* MDBX_ENV_CHECKPID */ @@ -8052,7 +8059,7 @@ int mdbx_txn_commit(MDBX_txn *txn) { goto done; if (txn->mt_child) { - rc = mdbx_txn_commit(txn->mt_child); + rc = mdbx_txn_commit_ex(txn->mt_child, NULL); mdbx_tassert(txn, txn->mt_child == NULL); if (unlikely(rc != MDBX_SUCCESS)) goto fail; @@ -8107,6 +8114,7 @@ int mdbx_txn_commit(MDBX_txn *txn) { parent->mt_dbistate[i] = txn->mt_dbistate[i] | (parent->mt_dbistate[i] & (DBI_CREAT | DBI_FRESH)); } + ts_1 = latency ? mdbx_osal_monotime() : 0; /* Remove refunded pages from parent's dirty & spill lists */ MDBX_DPL dst = mdbx_dpl_sort(parent->tw.dirtylist); @@ -8278,6 +8286,7 @@ int mdbx_txn_commit(MDBX_txn *txn) { parent->mt_flags |= MDBX_TXN_SPILLS; } + ts_2 = latency ? mdbx_osal_monotime() : 0; /* Append our loose page list to parent's */ if (txn->tw.loose_pages) { MDBX_page **lp = &parent->tw.loose_pages; @@ -8299,8 +8308,6 @@ int mdbx_txn_commit(MDBX_txn *txn) { env->me_txn = parent; parent->mt_child = NULL; - txn->mt_signature = 0; - mdbx_free(txn); mdbx_tassert(parent, mdbx_dirtylist_check(parent)); /* Scan parent's loose page for suitable for refund */ @@ -8310,8 +8317,13 @@ int mdbx_txn_commit(MDBX_txn *txn) { break; } } + + ts_4 = ts_3 = latency ? mdbx_osal_monotime() : 0; + txn->mt_signature = 0; + mdbx_free(txn); mdbx_tassert(parent, mdbx_dirtylist_check(parent)); - return MDBX_SUCCESS; + rc = MDBX_SUCCESS; + goto provide_latency; } mdbx_tassert(txn, txn->tw.dirtyroom + txn->tw.dirtylist->length == @@ -8360,17 +8372,23 @@ int mdbx_txn_commit(MDBX_txn *txn) { } } + ts_1 = latency ? mdbx_osal_monotime() : 0; rc = mdbx_update_gc(txn); if (unlikely(rc != MDBX_SUCCESS)) goto fail; + ts_2 = latency ? mdbx_osal_monotime() : 0; if (mdbx_audit_enabled()) { rc = mdbx_audit_ex(txn, MDBX_PNL_SIZE(txn->tw.retired_pages), true); + const uint64_t audit_end = mdbx_osal_monotime(); + audit_duration = mdbx_osal_monotime_to_16dot16(audit_end - ts_2); + ts_2 = audit_end; if (unlikely(rc != MDBX_SUCCESS)) goto fail; } rc = mdbx_page_flush(txn, 0); + ts_3 = latency ? mdbx_osal_monotime() : 0; if (likely(rc == MDBX_SUCCESS)) { if (txn->mt_dbs[MAIN_DBI].md_flags & DBI_DIRTY) txn->mt_dbs[MAIN_DBI].md_mod_txnid = pp_txnid2chk(txn); @@ -8392,6 +8410,7 @@ int mdbx_txn_commit(MDBX_txn *txn) { rc = mdbx_sync_locked( env, env->me_flags | txn->mt_flags | MDBX_SHRINK_ALLOWED, &meta); } + ts_4 = latency ? mdbx_osal_monotime() : 0; if (unlikely(rc != MDBX_SUCCESS)) { env->me_flags |= MDBX_FATAL_ERROR; goto fail; @@ -8400,11 +8419,28 @@ int mdbx_txn_commit(MDBX_txn *txn) { end_mode = MDBX_END_COMMITTED | MDBX_END_UPDATE | MDBX_END_EOTDONE; done: - return mdbx_txn_end(txn, end_mode); + rc = mdbx_txn_end(txn, end_mode); + +provide_latency: + if (latency) { + latency->audit = audit_duration; + latency->preparation = + ts_1 ? mdbx_osal_monotime_to_16dot16(ts_1 - ts_0) : 0; + latency->gc = + (ts_1 && ts_2) ? mdbx_osal_monotime_to_16dot16(ts_2 - ts_1) : 0; + latency->write = + (ts_2 && ts_3) ? mdbx_osal_monotime_to_16dot16(ts_3 - ts_2) : 0; + latency->sync = + (ts_3 && ts_4) ? mdbx_osal_monotime_to_16dot16(ts_4 - ts_3) : 0; + const uint64_t ts_5 = mdbx_osal_monotime(); + latency->ending = ts_4 ? mdbx_osal_monotime_to_16dot16(ts_5 - ts_4) : 0; + latency->whole = mdbx_osal_monotime_to_16dot16(ts_5 - ts_0); + } + return rc; fail: mdbx_txn_abort(txn); - return rc; + goto provide_latency; } static __cold int