Import wiredtiger: 55e953e187acabfc120123ccc4d619c0777da01a from branch mongodb-master

ref: 49031a8fb9..55e953e187
for: 6.3.0-rc0

WT-9796 Add debugging for logging getting stuck.

1 files changed, 27 insertions, 3 deletions

diff --git a/src/third_party/wiredtiger/src/log/log.c b/src/third_party/wiredtiger/src/log/log.c
index 1311f91f901..664795625b2 100644
--- a/src/third_party/wiredtiger/src/log/log.c
+++ b/src/third_party/wiredtiger/src/log/log.c
@@ -705,7 +705,7 @@ __wt_log_fill(
 
     WT_STAT_CONN_INCRV(session, log_bytes_written, record->size);
     if (lsnp != NULL) {
-        *lsnp = myslot->slot->slot_start_lsn;
+        WT_ASSIGN_LSN(lsnp, &myslot->slot->slot_start_lsn);
         lsnp->l.offset += (uint32_t)myslot->offset;
     }
 err:
@@ -1859,6 +1859,12 @@ __wt_log_release(WT_SESSION_IMPL *session, WT_LOGSLOT *slot, bool *freep)
         *freep = 1;
     release_buffered = WT_LOG_SLOT_RELEASED_BUFFERED(slot->slot_state);
     release_bytes = release_buffered + slot->slot_unbuffered;
+#ifdef HAVE_DIAGNOSTIC
+    slot->rel_sess = session;
+    slot->rel_flags = slot->flags;
+    WT_FULL_BARRIER();
+    WT_ASSERT(session, slot->rel_flags == slot->flags);
+#endif
 
     /*
      * Checkpoints can be configured based on amount of log written. Add in this log record to the
@@ -1972,11 +1978,11 @@ __wt_log_release(WT_SESSION_IMPL *session, WT_LOGSLOT *slot, bool *freep)
             __wt_verbose(session, WT_VERB_LOG,
               "log_release: sync log %s to LSN %" PRIu32 "/%" PRIu32, log->log_fh->name,
               sync_lsn.l.file, sync_lsn.l.offset);
-            WT_STAT_CONN_INCR(session, log_sync);
             time_start = __wt_clock(session);
             WT_ERR(__wt_fsync(session, log->log_fh, true));
             time_stop = __wt_clock(session);
             fsync_duration_usecs = WT_CLOCKDIFF_US(time_stop, time_start);
+            WT_STAT_CONN_INCR(session, log_sync);
             WT_STAT_CONN_INCRV(session, log_sync_duration, fsync_duration_usecs);
             WT_ASSIGN_LSN(&log->sync_lsn, &sync_lsn);
             __wt_cond_signal(session, log->log_sync_cond);
@@ -2572,6 +2578,11 @@ __log_write_internal(WT_SESSION_IMPL *session, WT_ITEM *record, WT_LSN *lsnp, ui
     int64_t release_size;
     uint32_t fill_size, force, rdup_len;
     bool free_slot;
+#ifdef HAVE_DIAGNOSTIC
+    WT_LOGSLOT dbgslot[4];
+
+    memset(dbgslot, 0, sizeof(dbgslot));
+#endif
 
     conn = S2C(session);
     log = conn->log;
@@ -2646,6 +2657,9 @@ __log_write_internal(WT_SESSION_IMPL *session, WT_ITEM *record, WT_LSN *lsnp, ui
      * The only time joining a slot should ever return an error is if it detects a panic.
      */
     __wt_log_slot_join(session, rdup_len, flags, &myslot);
+#ifdef HAVE_DIAGNOSTIC
+    dbgslot[0] = *myslot.slot;
+#endif
     /*
      * If the addition of this record crosses the buffer boundary, switch in a new slot.
      */
@@ -2664,10 +2678,16 @@ __log_write_internal(WT_SESSION_IMPL *session, WT_ITEM *record, WT_LSN *lsnp, ui
         myslot.slot->slot_error = ret;
     WT_ASSERT(session, ret == 0);
     if (WT_LOG_SLOT_DONE(release_size)) {
+#ifdef HAVE_DIAGNOSTIC
+        dbgslot[1] = *myslot.slot;
+#endif
         WT_ERR(__wt_log_release(session, myslot.slot, &free_slot));
         if (free_slot)
             __wt_log_slot_free(session, myslot.slot);
     } else if (force) {
+#ifdef HAVE_DIAGNOSTIC
+        dbgslot[2] = *myslot.slot;
+#endif
         /*
          * If we are going to wait for this slot to get written, signal the log server thread.
          *
@@ -2685,13 +2705,17 @@ __log_write_internal(WT_SESSION_IMPL *session, WT_ITEM *record, WT_LSN *lsnp, ui
             __wt_cond_wait(session, log->log_write_cond, 10000, NULL);
     } else if (LF_ISSET(WT_LOG_FSYNC)) {
         /* Wait for our writes to reach disk */
+#ifdef HAVE_DIAGNOSTIC
+        /* NOTE: the slot could be reused and contain unrelated information. Copy it anyway. */
+        dbgslot[3] = *myslot.slot;
+#endif
         while (__wt_log_cmp(&log->sync_lsn, &lsn) <= 0 && myslot.slot->slot_error == 0)
             __wt_cond_wait(session, log->log_sync_cond, 10000, NULL);
     }
 
 err:
     if (ret == 0 && lsnp != NULL)
-        *lsnp = lsn;
+        WT_ASSIGN_LSN(lsnp, &lsn);
     /*
      * If we're synchronous and some thread had an error, we don't know if our write made it out to
      * the file or not. The error could be before or after us. So, if anyone got an error, we report