Expose commit latency struct for profiling

src/database.rs

@@ -1,5 +1,6 @@
 use crate::{
     error::{mdbx_result, Error, Result},
+    latency::CommitLatency,
     table::Table,
     transaction::{RO, RW},
     Mode, ReadWriteOptions, SyncMode, Transaction, TransactionKind,
@@ -77,7 +78,7 @@ pub(crate) enum TxnManagerMessage {
     },
     Commit {
         tx: TxnPtr,
-        sender: SyncSender<Result<bool>>,
+        sender: SyncSender<Result<(bool, CommitLatency)>>,
     },
 }
 
@@ -284,10 +285,14 @@ where
                                 .unwrap();
                         }
                         TxnManagerMessage::Commit { tx, sender } => {
+                            let mut latency = CommitLatency::new();
                             sender
-                                .send(mdbx_result(unsafe {
-                                    ffi::mdbx_txn_commit_ex(tx.0, ptr::null_mut())
-                                }))
+                                .send(
+                                    mdbx_result(unsafe {
+                                        ffi::mdbx_txn_commit_ex(tx.0, &mut latency.0)
+                                    })
+                                    .map(|v| (v, latency)),
+                                )
                                 .unwrap();
                         }
                     },

src/latency.rs

@@ -0,0 +1,68 @@
+use std::{mem, time::Duration};
+
+/// Latency statistics for committing transactions.
+#[derive(Debug)]
+pub struct CommitLatency(pub(crate) ffi::MDBX_commit_latency);
+
+impl CommitLatency {
+    pub fn new() -> Self {
+        unsafe { Self(mem::zeroed()) }
+    }
+
+    /// Duration of preparation (commit child transactions, update
+    /// sub-databases records and cursors destroying).
+    #[inline]
+    pub const fn preparation(&self) -> Duration {
+        Self::time_to_duration(self.0.preparation)
+    }
+
+    /// Duration of GC/freeDB handling & updation.
+    #[inline]
+    pub const fn gc_wallclock(&self) -> Duration {
+        Self::time_to_duration(self.0.gc_wallclock)
+    }
+
+    /// Duration of internal audit if enabled.
+    #[inline]
+    pub const fn audit(&self) -> Duration {
+        Self::time_to_duration(self.0.audit)
+    }
+
+    /// Duration of writing dirty/modified data pages to a filesystem,
+    /// i.e. the summary duration of a `write()` syscalls during commit.
+    #[inline]
+    pub const fn write(&self) -> Duration {
+        Self::time_to_duration(self.0.write)
+    }
+
+    /// Duration of syncing written data to the disk/storage, i.e.
+    /// the duration of a `fdatasync()` or a `msync()` syscall during commit.
+    #[inline]
+    pub const fn sync(&self) -> Duration {
+        Self::time_to_duration(self.0.sync)
+    }
+
+    /// Duration of transaction ending (releasing resources).
+    #[inline]
+    pub const fn ending(&self) -> Duration {
+        Self::time_to_duration(self.0.ending)
+    }
+
+    /// The total duration of a commit.
+    #[inline]
+    pub const fn whole(&self) -> Duration {
+        Self::time_to_duration(self.0.whole)
+    }
+
+    /// User-mode CPU time spent on GC update.
+    #[inline]
+    pub const fn gc_cputime(&self) -> Duration {
+        Self::time_to_duration(self.0.gc_cputime)
+    }
+
+    /// Latency of commit stages in 1/65_536 of seconds units.
+    #[inline]
+    const fn time_to_duration(time: u32) -> Duration {
+        Duration::from_nanos(time as u64 * (1_000_000_000 / 65_536))
+    }
+}

src/lib.rs

@@ -19,6 +19,7 @@ mod cursor;
 mod database;
 mod error;
 mod flags;
+mod latency;
 mod table;
 mod transaction;
 

src/transaction.rs

@@ -2,6 +2,7 @@ use crate::{
     database::{Database, DatabaseKind, NoWriteMap, TxnManagerMessage, TxnPtr},
     error::{mdbx_result, Result},
     flags::{c_enum, TableFlags, WriteFlags},
+    latency::CommitLatency,
     table::Table,
     Cursor, Decodable, Error, Stat,
 };
@@ -152,11 +153,16 @@ where
     }
 
     /// Commits the transaction and returns table handles permanently open for the lifetime of `Database`.
-    pub fn commit_and_rebind_open_dbs(mut self) -> Result<(bool, Vec<Table<'db>>)> {
+    /// Also returns measured latency.
+    pub fn commit_and_rebind_open_dbs_with_latency(
+        mut self,
+    ) -> Result<(bool, CommitLatency, Vec<Table<'db>>)> {
         let txnlck = self.txn.lock();
         let txn = txnlck.0;
         let result = if K::ONLY_CLEAN {
-            mdbx_result(unsafe { ffi::mdbx_txn_commit_ex(txn, ptr::null_mut()) })
+            let mut latency = CommitLatency::new();
+            mdbx_result(unsafe { ffi::mdbx_txn_commit_ex(txn, &mut latency.0) })
+                .map(|v| (v, latency))
         } else {
             let (sender, rx) = sync_channel(0);
             self.db
@@ -171,9 +177,10 @@ where
             rx.recv().unwrap()
         };
         self.committed = true;
-        result.map(|v| {
+        result.map(|(v, latency)| {
             (
                 v,
+                latency,
                 self.primed_dbis
                     .lock()
                     .iter()
@@ -183,6 +190,13 @@ where
         })
     }
 
+    /// Commits the transaction and returns table handles permanently open for the lifetime of `Database`.
+    pub fn commit_and_rebind_open_dbs(self) -> Result<(bool, Vec<Table<'db>>)> {
+        // Drop `CommitLatency` from return value.
+        self.commit_and_rebind_open_dbs_with_latency()
+            .map(|v| (v.0, v.2))
+    }
+
     /// Opens a handle to an MDBX table.
     ///
     /// If `name` is [None], then the returned handle will be for the default table.