Import wiredtiger: ab4d65609f8af6bdad6dfcc889406991f5b5be6c from branch mongodb-master

ref: ee9edd2f22..ab4d65609f
for: 6.2.0-rc0

WT-9922 Add more debug log levels (#8389)

13 files changed, 66 insertions, 40 deletions

diff --git a/src/third_party/wiredtiger/dist/s_define.list b/src/third_party/wiredtiger/dist/s_define.list
index d79519f70ec..4040226b9ce 100644
--- a/src/third_party/wiredtiger/dist/s_define.list
+++ b/src/third_party/wiredtiger/dist/s_define.list
@@ -90,6 +90,7 @@ WT_TXN_UPDATE
 WT_UPDATE_SIZE
 WT_USE_OPENAT
 WT_VERBOSE_CATEGORY_DEFAULT
+WT_VERBOSE_DEBUG
 WT_VERBOSE_LEVEL_DEFAULT
 WT_WITH_LOCK_NOWAIT
 WT_WITH_LOCK_WAIT
diff --git a/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_log_system.h b/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_log_system.h
index 5542b1b3bc9..3e6b2c42e21 100644
--- a/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_log_system.h
+++ b/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_log_system.h
@@ -43,7 +43,11 @@ static const std::map<int32_t, Aws::Utils::Logging::LogLevel> verbosityMapping =
   {WT_VERBOSE_WARNING, Aws::Utils::Logging::LogLevel::Error},
   {WT_VERBOSE_WARNING, Aws::Utils::Logging::LogLevel::Warn},
   {WT_VERBOSE_INFO, Aws::Utils::Logging::LogLevel::Info},
-  {WT_VERBOSE_DEBUG, Aws::Utils::Logging::LogLevel::Debug}};
+  {WT_VERBOSE_DEBUG_1, Aws::Utils::Logging::LogLevel::Debug},
+  {WT_VERBOSE_DEBUG_2, Aws::Utils::Logging::LogLevel::Debug},
+  {WT_VERBOSE_DEBUG_3, Aws::Utils::Logging::LogLevel::Debug},
+  {WT_VERBOSE_DEBUG_4, Aws::Utils::Logging::LogLevel::Debug},
+  {WT_VERBOSE_DEBUG_5, Aws::Utils::Logging::LogLevel::Trace}};
 
 // Provides the S3 Store with a logger implementation that redirects the generated logs to
 // WiredTiger's logging streams. This class implements AWS's LogSystemInterface class, an interface
@@ -73,7 +77,7 @@ class S3LogSystem : public Aws::Utils::Logging::LogSystemInterface {
     void
     LogDebugMessage(const std::string &message) const
     {
-        LogVerboseMessage(WT_VERBOSE_DEBUG, message);
+        LogVerboseMessage(WT_VERBOSE_DEBUG_1, message);
     }
 
     // Sets the WiredTiger Extension's verbosity level and matches the AWS log levels
diff --git a/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_storage_source.cpp b/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_storage_source.cpp
index 4b66197845a..4010c5bcf99 100644
--- a/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_storage_source.cpp
+++ b/src/third_party/wiredtiger/ext/storage_sources/s3_store/s3_storage_source.cpp
@@ -869,7 +869,7 @@ wiredtiger_extension_init(WT_CONNECTION *connection, WT_CONFIG_ARG *config)
     s3->verbose = WT_VERBOSE_ERROR;
     s3->log = Aws::MakeShared<S3LogSystem>("storage", s3->wtApi, s3->verbose);
 
-    if (ret == 0 && v.val >= WT_VERBOSE_ERROR && v.val <= WT_VERBOSE_DEBUG) {
+    if (ret == 0 && v.val >= WT_VERBOSE_ERROR && v.val <= WT_VERBOSE_DEBUG_5) {
         s3->verbose = v.val;
         s3->log->SetWtVerbosityLevel(s3->verbose);
     } else if (ret != WT_NOTFOUND) {
diff --git a/src/third_party/wiredtiger/import.data b/src/third_party/wiredtiger/import.data
index ba4cd44e80e..3f2e2bcd92b 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": "ee9edd2f225102800d0a6c29cda1f53eb35c20c3"
+    "commit": "ab4d65609f8af6bdad6dfcc889406991f5b5be6c"
 }
diff --git a/src/third_party/wiredtiger/src/block/block_compact.c b/src/third_party/wiredtiger/src/block/block_compact.c
index 098832cbfb6..a033e5cefa8 100644
--- a/src/third_party/wiredtiger/src/block/block_compact.c
+++ b/src/third_party/wiredtiger/src/block/block_compact.c
@@ -42,7 +42,7 @@ __wt_block_compact_end(WT_SESSION_IMPL *session, WT_BLOCK *block)
     __wt_block_configure_first_fit(block, false);
 
     /* Dump the results of the compaction pass. */
-    if (WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_COMPACT, WT_VERBOSE_DEBUG)) {
+    if (WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_COMPACT, WT_VERBOSE_DEBUG_1)) {
         __wt_spin_lock(session, &block->live_lock);
         __block_dump_file_stat(session, block, false);
         __wt_spin_unlock(session, &block->live_lock);
@@ -77,7 +77,7 @@ __wt_block_compact_progress(WT_SESSION_IMPL *session, WT_BLOCK *block, u_int *ms
     struct timespec cur_time;
     uint64_t time_diff;
 
-    if (!WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_COMPACT_PROGRESS, WT_VERBOSE_DEBUG))
+    if (!WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_COMPACT_PROGRESS, WT_VERBOSE_DEBUG_1))
         return;
 
     __wt_epoch(session, &cur_time);
@@ -121,7 +121,7 @@ __wt_block_compact_skip(WT_SESSION_IMPL *session, WT_BLOCK *block, bool *skipp)
     __wt_spin_lock(session, &block->live_lock);
 
     /* Dump the current state of the file. */
-    if (WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_COMPACT, WT_VERBOSE_DEBUG))
+    if (WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_COMPACT, WT_VERBOSE_DEBUG_1))
         __block_dump_file_stat(session, block, true);
 
     /* Sum the available bytes in the initial 80% and 90% of the file. */
diff --git a/src/third_party/wiredtiger/src/block/block_ext.c b/src/third_party/wiredtiger/src/block/block_ext.c
index a4451ea00e0..17357c21958 100644
--- a/src/third_party/wiredtiger/src/block/block_ext.c
+++ b/src/third_party/wiredtiger/src/block/block_ext.c
@@ -1353,7 +1353,7 @@ __block_extlist_dump(WT_SESSION_IMPL *session, WT_BLOCK *block, WT_EXTLIST *el,
     if (block->verify_layout)
         level = WT_VERBOSE_NOTICE;
     else
-        level = WT_VERBOSE_DEBUG;
+        level = WT_VERBOSE_DEBUG_1;
     __wt_verbose_level(session, WT_VERB_BLOCK, level,
       "%s extent list %s, %" PRIu32 " entries, %s bytes", tag, el->name, el->entries,
       __wt_buf_set_size(session, el->bytes, true, t1));
diff --git a/src/third_party/wiredtiger/src/conn/conn_api.c b/src/third_party/wiredtiger/src/conn/conn_api.c
index ddeb8719590..38bd79e6230 100644
--- a/src/third_party/wiredtiger/src/conn/conn_api.c
+++ b/src/third_party/wiredtiger/src/conn/conn_api.c
@@ -2141,13 +2141,13 @@ __wt_verbose_config(WT_SESSION_IMPL *session, const char *cfg[], bool reconfig)
         else if (sval.type == WT_CONFIG_ITEM_BOOL && sval.len == 0)
             /*
              * If no value is associated with the event (i.e passing verbose=[checkpoint]), default
-             * the event to WT_VERBOSE_DEBUG. Correspondingly, all legacy uses of '__wt_verbose',
+             * the event to WT_VERBOSE_DEBUG_1. Correspondingly, all legacy uses of '__wt_verbose',
              * being messages without an explicit verbosity level, will default to
-             * 'WT_VERBOSE_DEBUG'.
+             * 'WT_VERBOSE_DEBUG_1'.
              */
-            conn->verbose[ft->flag] = WT_VERBOSE_DEBUG;
+            conn->verbose[ft->flag] = WT_VERBOSE_DEBUG_1;
         else if (sval.type == WT_CONFIG_ITEM_NUM && sval.val >= WT_VERBOSE_INFO &&
-          sval.val <= WT_VERBOSE_DEBUG)
+          sval.val <= WT_VERBOSE_DEBUG_5)
             conn->verbose[ft->flag] = (WT_VERBOSE_LEVEL)sval.val;
         else
             /*
diff --git a/src/third_party/wiredtiger/src/evict/evict_lru.c b/src/third_party/wiredtiger/src/evict/evict_lru.c
index fd76f2b5aa1..63fa232bd39 100644
--- a/src/third_party/wiredtiger/src/evict/evict_lru.c
+++ b/src/third_party/wiredtiger/src/evict/evict_lru.c
@@ -461,9 +461,9 @@ __evict_server(WT_SESSION_IMPL *session, bool *did_work)
 #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);
+        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT, WT_VERBOSE_DEBUG_1);
+        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICTSERVER, WT_VERBOSE_DEBUG_1);
+        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT_STUCK, WT_VERBOSE_DEBUG_1);
         verbose_timeout_flags = true;
     }
 #endif
diff --git a/src/third_party/wiredtiger/src/include/txn_inline.h b/src/third_party/wiredtiger/src/include/txn_inline.h
index 47b307de272..fda90ec7bbc 100644
--- a/src/third_party/wiredtiger/src/include/txn_inline.h
+++ b/src/third_party/wiredtiger/src/include/txn_inline.h
@@ -1471,7 +1471,7 @@ __wt_txn_modify_block(
 
     if (rollback) {
         /* Dump information about the txn snapshot. */
-        if (WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_TRANSACTION, WT_VERBOSE_DEBUG)) {
+        if (WT_VERBOSE_LEVEL_ISSET(session, WT_VERB_TRANSACTION, WT_VERBOSE_DEBUG_1)) {
             WT_ERR(__wt_scr_alloc(session, 1024, &buf));
             WT_ERR(__wt_buf_fmt(session, buf,
               "snapshot_min=%" PRIu64 ", snapshot_max=%" PRIu64 ", snapshot_count=%" PRIu32,
diff --git a/src/third_party/wiredtiger/src/include/verbose.h b/src/third_party/wiredtiger/src/include/verbose.h
index e457e6e4b11..2aeb383b7e2 100644
--- a/src/third_party/wiredtiger/src/include/verbose.h
+++ b/src/third_party/wiredtiger/src/include/verbose.h
@@ -74,18 +74,30 @@
         case WT_VERBOSE_INFO:                  \
             (level_str) = "INFO";              \
             break;                             \
-        case WT_VERBOSE_DEBUG:                 \
-            (level_str) = "DEBUG";             \
+        case WT_VERBOSE_DEBUG_1:               \
+            (level_str) = "DEBUG_1";           \
+            break;                             \
+        case WT_VERBOSE_DEBUG_2:               \
+            (level_str) = "DEBUG_2";           \
+            break;                             \
+        case WT_VERBOSE_DEBUG_3:               \
+            (level_str) = "DEBUG_3";           \
+            break;                             \
+        case WT_VERBOSE_DEBUG_4:               \
+            (level_str) = "DEBUG_4";           \
+            break;                             \
+        case WT_VERBOSE_DEBUG_5:               \
+            (level_str) = "DEBUG_5";           \
             break;                             \
         }                                      \
     } while (0)
 
 /*
- * Default verbosity level. WT_VERBOSE_DEBUG being the default level assigned to verbose messages
+ * Default verbosity level. WT_VERBOSE_DEBUG_1 being the default level assigned to verbose messages
  * prior to the introduction of verbosity levels.
  */
 #ifndef WT_VERBOSE_LEVEL_DEFAULT
-#define WT_VERBOSE_LEVEL_DEFAULT WT_VERBOSE_DEBUG
+#define WT_VERBOSE_LEVEL_DEFAULT WT_VERBOSE_DEBUG_1
 #endif
 
 /* Default category for messages that don't explicitly specify a category. */
@@ -162,7 +174,7 @@ struct __wt_verbose_multi_category {
  *     Wrapper to __wt_verbose_level using the default verbosity level.
  */
 #define __wt_verbose_debug(session, category, fmt, ...) \
-    __wt_verbose_level(session, category, WT_VERBOSE_DEBUG, fmt, __VA_ARGS__)
+    __wt_verbose_level(session, category, WT_VERBOSE_DEBUG_1, fmt, __VA_ARGS__)
 
 /*
  * __wt_verbose --
diff --git a/src/third_party/wiredtiger/src/include/wiredtiger.in b/src/third_party/wiredtiger/src/include/wiredtiger.in
index cb5bd37d0c9..49636c137df 100644
--- a/src/third_party/wiredtiger/src/include/wiredtiger.in
+++ b/src/third_party/wiredtiger/src/include/wiredtiger.in
@@ -7495,7 +7495,7 @@ typedef enum {
 /*!
  * WiredTiger verbosity levels. The levels define a range of severity categories, with
  * \c WT_VERBOSE_ERROR being the lowest, most critical level (used by messages on critical error
- * paths) and \c WT_VERBOSE_DEBUG being the highest verbosity/informational level (mostly adopted
+ * paths) and \c WT_VERBOSE_DEBUG_5 being the highest verbosity/informational level (mostly adopted
  * for debugging).
  */
 typedef enum {
@@ -7505,8 +7505,16 @@ typedef enum {
     WT_VERBOSE_NOTICE,      /*!< Messages for significant events in WiredTiger, usually worth
                             noting. */
     WT_VERBOSE_INFO,        /*!< Informational style messages. */
-    WT_VERBOSE_DEBUG        /*!< Low severity messages, useful for debugging purposes. */
+    WT_VERBOSE_DEBUG_1,     /*!< Low severity messages, useful for debugging purposes. This is
+                            the default level when debugging. */
+    WT_VERBOSE_DEBUG_2,     /*!< Low severity messages, an increase in verbosity from
+                            the previous level. */
+    WT_VERBOSE_DEBUG_3,     /*!< Low severity messages. */
+    WT_VERBOSE_DEBUG_4,     /*!< Low severity messages. */
+    WT_VERBOSE_DEBUG_5      /*!< Lowest severity messages. */
 } WT_VERBOSE_LEVEL;
+/*! Temporary, for compatibility. FIXME: SERVER-70652. */
+#define WT_VERBOSE_DEBUG WT_VERBOSE_DEBUG_1
 /*! @} */
 /*
  * Verbose section: END
diff --git a/src/third_party/wiredtiger/src/support/generation.c b/src/third_party/wiredtiger/src/support/generation.c
index 121b755f29f..88af5655bef 100644
--- a/src/third_party/wiredtiger/src/support/generation.c
+++ b/src/third_party/wiredtiger/src/support/generation.c
@@ -176,14 +176,15 @@ __wt_gen_drain(WT_SESSION_IMPL *session, int which, uint64_t generation)
                 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);
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT, WT_VERBOSE_DEBUG_1);
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICTSERVER, WT_VERBOSE_DEBUG_1);
+                        WT_SET_VERBOSE_LEVEL(session, WT_VERB_EVICT_STUCK, WT_VERBOSE_DEBUG_1);
                     } 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, WT_VERBOSE_DEBUG_1);
                         WT_SET_VERBOSE_LEVEL(
-                          session, WT_VERB_CHECKPOINT_PROGRESS, WT_VERBOSE_DEBUG);
+                          session, WT_VERB_CHECKPOINT_CLEANUP, WT_VERBOSE_DEBUG_1);
+                        WT_SET_VERBOSE_LEVEL(
+                          session, WT_VERB_CHECKPOINT_PROGRESS, WT_VERBOSE_DEBUG_1);
                     }
                     verbose_timeout_flags = true;
                 }
diff --git a/src/third_party/wiredtiger/test/suite/test_verbose02.py b/src/third_party/wiredtiger/test/suite/test_verbose02.py
index c7ad990d951..a7f6128fbce 100755
--- a/src/third_party/wiredtiger/test/suite/test_verbose02.py
+++ b/src/third_party/wiredtiger/test/suite/test_verbose02.py
@@ -52,11 +52,11 @@ class test_verbose02(test_verbose_base):
         self.close_conn()
 
         # Test passing a single verbose category, 'api' along with the verbosity level
-        # WT_VERBOSE_DEBUG (1). Ensuring the only verbose output generated is related to the 'api'
-        # category.
+        # WT_VERBOSE_DEBUG_1 (1). Ensuring the only verbose output generated is related to the
+        # 'api' category.
         with self.expect_verbose(['api:1'], ['WT_VERB_API'], self.is_json) as conn:
             # Perform a set of simple API operations to generate verbose API messages.
-            uri = 'table:test_verbose01_api'
+            uri = 'table:test_verbose02_api'
             session = conn.open_session()
             session.create(uri, self.collection_cfg)
             c = session.open_cursor(uri)
@@ -67,7 +67,7 @@ class test_verbose02(test_verbose_base):
         # At this time, there is no verbose messages with the category WT_VERB_API and the verbosity
         # level WT_VERBOSE_INFO (0), hence we don't expect any output.
         with self.expect_verbose(['api:0'], ['WT_VERB_API'], self.is_json, False) as conn:
-            uri = 'table:test_verbose01_api'
+            uri = 'table:test_verbose02_api'
             session = conn.open_session()
             session.create(uri, self.collection_cfg)
             c = session.open_cursor(uri)
@@ -76,15 +76,15 @@ class test_verbose02(test_verbose_base):
             session.close()
 
         # Test passing another single verbose category, 'compact' with different verbosity levels.
-        # Since there are verbose message with the category WT_VERB_COMPACT and the verbosity levels
-        # WT_VERBOSE_INFO (0) and WT_VERBOSE_DEBUG (1), we can test them both.
-        cfgs = ['compact:0', 'compact:1']
+        # Since there are verbose messages with the category WT_VERB_COMPACT and the verbosity
+        # levels WT_VERBOSE_INFO (0) through WT_VERBOSE_DEBUG_5 (5), we can test them all.
+        cfgs = ['compact:0', 'compact:1', 'compact:2', 'compact:3', 'compact:4', 'compact:5']
         for cfg in cfgs:
             with self.expect_verbose([cfg], ['WT_VERB_COMPACT'], self.is_json) as conn:
                 # Create a simple table to invoke compaction on. We aren't doing anything
                 # interesting with the table, we want to simply invoke a compaction pass to generate
                 # verbose messages.
-                uri = 'table:test_verbose01_compact'
+                uri = 'table:test_verbose02_compact'
                 session = conn.open_session()
                 session.create(uri, self.collection_cfg)
                 session.compact(uri)
@@ -103,7 +103,7 @@ class test_verbose02(test_verbose_base):
                 # Perform a set of simple API operations (table creations and cursor operations) to
                 # generate verbose API messages. Beyond opening the connection resource, we
                 # shouldn't need to do anything special for the version category.
-                uri = 'table:test_verbose01_multiple'
+                uri = 'table:test_verbose02_multiple'
                 session = conn.open_session()
                 session.create(uri, self.collection_cfg)
                 c = session.open_cursor(uri)
@@ -118,9 +118,9 @@ class test_verbose02(test_verbose_base):
         self.assertRaisesHavingMessage(wiredtiger.WiredTigerError,
                 lambda:self.wiredtiger_open(self.home, 'verbose=[api:-1]'),
                 '/Failed to parse verbose option \'api\'/')
-        # Any value greater than WT_VERBOSE_DEBUG (1) is invalid.
+        # Any value greater than WT_VERBOSE_DEBUG_5 (5) is invalid.
         self.assertRaisesHavingMessage(wiredtiger.WiredTigerError,
-                lambda:self.wiredtiger_open(self.home, 'verbose=[api:2]'),
+                lambda:self.wiredtiger_open(self.home, 'verbose=[api:6]'),
                 '/Failed to parse verbose option \'api\'/')
 
 if __name__ == '__main__':