Import wiredtiger: f1646b537667ed61d1c43875e60f7188415b5d74 from branch mongodb-master

ref: fe6c936cee..f1646b5376
for: 6.0.0

WT-8773       Enable more logs in specific scenarios

5 files changed, 53 insertions, 10 deletions

diff --git a/src/third_party/wiredtiger/import.data b/src/third_party/wiredtiger/import.data
index b2e6c946fb3..0dde9171a99 100644
--- a/src/third_party/wiredtiger/import.data
+++ b/src/third_party/wiredtiger/import.data
@@ -2,5 +2,5 @@
     "vendor": "wiredtiger",
     "github": "wiredtiger/wiredtiger.git",
     "branch": "mongodb-master",
-    "commit": "fe6c936cee7b6d3329e1d4df8da5aa56acfa7abb"
+    "commit": "f1646b537667ed61d1c43875e60f7188415b5d74"
 }
diff --git a/src/third_party/wiredtiger/src/evict/evict_lru.c b/src/third_party/wiredtiger/src/evict/evict_lru.c
index 6788809dcf9..462c387871e 100644
--- a/src/third_party/wiredtiger/src/evict/evict_lru.c
+++ b/src/third_party/wiredtiger/src/evict/evict_lru.c
@@ -378,12 +378,19 @@ __evict_server(WT_SESSION_IMPL *session, bool *did_work)
     WT_CACHE *cache;
     WT_CONNECTION_IMPL *conn;
     WT_DECL_RET;
+    uint64_t time_diff_ms;
+#ifdef HAVE_DIAGNOSTIC
+    bool verbose_timeout_flags;
+#endif
 
     /* Assume there has been no progress. */
     *did_work = false;
 
     conn = S2C(session);
     cache = conn->cache;
+#ifdef HAVE_DIAGNOSTIC
+    verbose_timeout_flags = false;
+#endif
 
     /* Evict pages from the cache as needed. */
     WT_RET(__evict_pass(session));
@@ -448,8 +455,21 @@ __evict_server(WT_SESSION_IMPL *session, bool *did_work)
         return (0);
 
     __wt_epoch(session, &now);
-    if (WT_TIMEDIFF_SEC(now, cache->stuck_time) > WT_MINUTE * 5) {
-#if defined(HAVE_DIAGNOSTIC)
+
+#define WT_CACHE_STUCK_TIMEOUT_MS 300000
+    time_diff_ms = WT_TIMEDIFF_MS(now, cache->stuck_time);
+#ifdef HAVE_DIAGNOSTIC
+    /* Enable extra logs 20ms before timing out. */
+    if (!verbose_timeout_flags && time_diff_ms > WT_CACHE_STUCK_TIMEOUT_MS - 20) {
+        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT, WT_VERBOSE_DEBUG);
+        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICTSERVER, WT_VERBOSE_DEBUG);
+        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT_STUCK, WT_VERBOSE_DEBUG);
+        verbose_timeout_flags = true;
+    }
+#endif
+
+    if (time_diff_ms > WT_CACHE_STUCK_TIMEOUT_MS) {
+#ifdef HAVE_DIAGNOSTIC
         __wt_err(session, ETIMEDOUT, "Cache stuck for too long, giving up");
         WT_RET(__wt_verbose_dump_txn(session));
         WT_RET(__wt_verbose_dump_cache(session));
diff --git a/src/third_party/wiredtiger/src/include/connection.h b/src/third_party/wiredtiger/src/include/connection.h
index a22be3d578d..2723ee14570 100644
--- a/src/third_party/wiredtiger/src/include/connection.h
+++ b/src/third_party/wiredtiger/src/include/connection.h
@@ -579,7 +579,7 @@ struct __wt_connection_impl {
 #define WT_JSON_OUTPUT_ERROR 0x1u
 #define WT_JSON_OUTPUT_MESSAGE 0x2u
     /* AUTOMATIC FLAG VALUE GENERATION STOP 8 */
-    uint8_t json_output; /* Output event handler messages in JSON format */
+    uint8_t json_output; /* Output event handler messages in JSON format. */
 
 /*
  * Variable with flags for which subsystems the diagnostic stress timing delays have been requested.
diff --git a/src/third_party/wiredtiger/src/include/verbose.h b/src/third_party/wiredtiger/src/include/verbose.h
index 1102e47db4f..e457e6e4b11 100644
--- a/src/third_party/wiredtiger/src/include/verbose.h
+++ b/src/third_party/wiredtiger/src/include/verbose.h
@@ -106,6 +106,9 @@ struct __wt_verbose_multi_category {
 #define WT_DECL_VERBOSE_MULTI_CATEGORY(items) \
     ((WT_VERBOSE_MULTI_CATEGORY){.categories = (items), .cnt = WT_ELEMENTS(items)})
 
+/* Set the verbosity level for a given category. */
+#define WT_SET_VERBOSE_LEVEL(session, category, level) S2C(session)->verbose[category] = level;
+
 /* Check if a given verbosity level satisfies the verbosity level of a category. */
 #define WT_VERBOSE_LEVEL_ISSET(session, category, level) (level <= S2C(session)->verbose[category])
 
diff --git a/src/third_party/wiredtiger/src/support/generation.c b/src/third_party/wiredtiger/src/support/generation.c
index ae493ac582f..02dfce6fe30 100644
--- a/src/third_party/wiredtiger/src/support/generation.c
+++ b/src/third_party/wiredtiger/src/support/generation.c
@@ -104,15 +104,18 @@ __wt_gen_next_drain(WT_SESSION_IMPL *session, int which)
 void
 __wt_gen_drain(WT_SESSION_IMPL *session, int which, uint64_t generation)
 {
+    struct timespec start, stop;
     WT_CONNECTION_IMPL *conn;
     WT_SESSION_IMPL *s;
-    uint64_t v, start, stop;
+    uint64_t time_diff_ms, v;
     uint32_t i, session_cnt;
     u_int minutes;
     int pause_cnt;
+    bool verbose_timeout_flags;
 
     conn = S2C(session);
-    start = 0; /* [-Wconditional-uninitialized] */
+    verbose_timeout_flags = false;
+    __wt_epoch(NULL, &start);
 
     /*
      * No lock is required because the session array is fixed size, but it may contain inactive
@@ -159,14 +162,31 @@ __wt_gen_drain(WT_SESSION_IMPL *session, int which, uint64_t generation)
              */
             if (minutes == 0) {
                 minutes = 1;
-                __wt_seconds(session, &start);
+                __wt_epoch(session, &start);
             } else {
-                __wt_seconds(session, &stop);
-                if (stop - start > minutes * WT_MINUTE) {
+                __wt_epoch(session, &stop);
+                time_diff_ms = WT_TIMEDIFF_MS(stop, start);
+#define WT_GEN_DRAIN_TIMEOUT_MIN 4
+                if (time_diff_ms > minutes * WT_MINUTE * WT_THOUSAND) {
                     __wt_verbose_notice(session, WT_VERB_GENERATION,
                       "%s generation drain waited %u minutes", __gen_name(which), minutes);
                     ++minutes;
-                    WT_ASSERT(session, minutes < 4);
+                    WT_ASSERT(session, minutes < WT_GEN_DRAIN_TIMEOUT_MIN);
+                }
+                /* Enable extra logs 20ms before timing out. */
+                else if (!verbose_timeout_flags &&
+                  time_diff_ms > (WT_GEN_DRAIN_TIMEOUT_MIN * WT_MINUTE * WT_THOUSAND - 20)) {
+                    if (which == WT_GEN_EVICT) {
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT, WT_VERBOSE_DEBUG);
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICTSERVER, WT_VERBOSE_DEBUG);
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT_STUCK, WT_VERBOSE_DEBUG);
+                    } else if (which == WT_GEN_CHECKPOINT) {
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_CHECKPOINT, WT_VERBOSE_DEBUG);
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_CHECKPOINT_CLEANUP, WT_VERBOSE_DEBUG);
+                        WT_SET_VERBOSE_LEVEL(
+                          session, WT_VERB_CHECKPOINT_PROGRESS, WT_VERBOSE_DEBUG);
+                    }
+                    verbose_timeout_flags = true;
                 }
             }
         }