[#27387] YSQL: Improve logging for incremental catalog cache refresh

Summary:
This diff makes some changes to improve logging incremental catalog cache
refresh to debugging a few cases found in QA stress test when full catalog
refreshes were performed unexpectedly.
Jira: DB-16921

Test Plan:
(1) ./yb_build.sh release --cxx-test pg_catalog_version-test

(2) start a RF-3 local cluster on my own dev vm, look at tserver logs to ensure
that there are no log flooding caused by this change when there is no DDL
statement executed.

Reviewers: kfranz, sanketh, mihnea

Reviewed By: kfranz

Subscribers: yql

Differential Revision: https://phorge.dev.yugabyte.com/D44459

Author: myang2021

src/yb/tserver/tablet_server.cc

@@ -1138,9 +1138,15 @@ Status TabletServer::SetTserverCatalogMessageList(
 
   int shm_index = -1;
   InvalidationMessagesQueue *db_message_lists = nullptr;
-  auto scope_exit = ScopeExit([this, &shm_index, &db_message_lists, db_oid, new_catalog_version] {
+  auto scope_exit = ScopeExit([this, &shm_index, &db_message_lists, db_oid, is_breaking_change,
+                               new_catalog_version] {
     if (shm_index >= 0) {
       shared_object()->SetYsqlDbCatalogVersion(static_cast<size_t>(shm_index), new_catalog_version);
+      if (FLAGS_log_ysql_catalog_versions) {
+        LOG_WITH_FUNC(INFO) << "set db " << db_oid
+                            << " catalog version: " << new_catalog_version
+                            << " is_breaking_change: " << is_breaking_change;
+      }
       InvalidatePgTableCache({{db_oid, new_catalog_version}} /* db_oids_updated */,
                              {} /* db_oids_deleted */);
     }
@@ -1461,6 +1467,9 @@ void TabletServer::SetYsqlDBCatalogVersionsUnlocked(
       // debugging the shared memory array db_catalog_versions_ (e.g., when we can dump
       // the shared memory file to examine its contents).
       shared_object()->SetYsqlDbCatalogVersion(static_cast<size_t>(shm_index), 0);
+      if (FLAGS_log_ysql_catalog_versions) {
+        LOG_WITH_FUNC(INFO) << "reset deleted db " << db_oid << " catalog version to 0";
+      }
     } else {
       ++it;
     }
@@ -1512,6 +1521,7 @@ void TabletServer::SetYsqlDBCatalogVersionsWithInvalMessages(
 void TabletServer::SetYsqlDBCatalogInvalMessagesUnlocked(
   const master::DBCatalogInvalMessagesDataPB& db_catalog_inval_messages_data) {
   if (db_catalog_inval_messages_data.db_catalog_inval_messages_size() == 0) {
+    LOG(INFO) << "empty db_catalog_inval_messages";
     return;
   }
   uint32_t current_db_oid = 0;
@@ -1604,12 +1614,14 @@ void TabletServer::MergeInvalMessagesIntoQueueUnlocked(
   // We do need to perform a merge, because both the queue and the incoming messages are sorted by
   // version, it is similar to a merge sort strategy.
   DoMergeInvalMessagesIntoQueueUnlocked(
-    db_catalog_inval_messages_data, start_index, end_index, &it->second.queue);
+    db_oid, db_catalog_inval_messages_data, start_index, end_index, &it->second.queue);
 }
 
 void TabletServer::DoMergeInvalMessagesIntoQueueUnlocked(
+  uint32_t db_oid,
   const master::DBCatalogInvalMessagesDataPB& db_catalog_inval_messages_data,
   int start_index, int end_index, InvalidationMessagesQueue *db_message_lists) {
+  bool changed = false;
   auto it = db_message_lists->begin();
   // Scan through each incoming pair, and insert it into the queue in the right position if
   // it does not already exist in the queue.
@@ -1637,16 +1649,22 @@ void TabletServer::DoMergeInvalMessagesIntoQueueUnlocked(
       ++it;
       ++start_index;
     } else if (incoming_version < existing_version) {
-      // The incoming version is lower, insert it before it.
-      VLOG(2) << "inserting version " << incoming_version;
+      std::string msg_info =
+          incoming_message_list.has_value() ? std::to_string(incoming_message_list.value().size())
+                                            : "nullopt";
+      // The incoming version is lower, insert before the iterator.
+      LOG(INFO) << "inserting version " << incoming_version << ", incoming_message_list: "
+                << msg_info << " before existing version " << existing_version
+                << ", db " << db_oid;
       it = db_message_lists->insert(it, std::make_pair(incoming_version, incoming_message_list));
+      changed = true;
       // After insertion, it points to the newly inserted incoming version, advance it to the
       // original existing version.
       ++it;
       ++start_index;
       DCHECK_EQ(it->first, existing_version);
     } else {
-      // The incoming version is higher, move it to the next existing slot in the queue.
+      // The incoming version is higher, move iterator to the next existing slot in the queue.
       // Keep start_index unchanged so that it can be compared with the next slot in the queue.
       VLOG(2) << "existing version: " << existing_version
               << ", higher incoming version: " << incoming_version;
@@ -1660,13 +1678,19 @@ void TabletServer::DoMergeInvalMessagesIntoQueueUnlocked(
     const uint64_t current_version = db_inval_messages.current_version();
     const std::optional<std::string>& message_list = db_inval_messages.has_message_list() ?
         std::optional<std::string>(db_inval_messages.message_list()) : std::nullopt;
-    VLOG(2) << "appending version " << current_version;
+    std::string msg_info = message_list.has_value() ? std::to_string(message_list.value().size())
+                                                    : "nullopt";
+    LOG(INFO) << "appending version " << current_version << ", message_list: " << msg_info
+              << ", db " << db_oid;
     db_message_lists->emplace_back(std::make_pair(current_version, message_list));
+    changed = true;
   }
-  VLOG(2) << "queue size: " << db_message_lists->size();
-  // We may have added more messages to the queue that exceeded the max size.
-  while (db_message_lists->size() > FLAGS_ysql_max_invalidation_message_queue_size) {
-    db_message_lists->pop_front();
+  if (changed) {
+    LOG(INFO) << "queue size: " << db_message_lists->size();
+    // We may have added more messages to the queue that exceeded the max size.
+    while (db_message_lists->size() > FLAGS_ysql_max_invalidation_message_queue_size) {
+      db_message_lists->pop_front();
+    }
   }
 }
 

src/yb/tserver/tablet_server.h

@@ -616,6 +616,7 @@ class TabletServer : public DbServerBase, public TabletServerIf {
       int start_index,
       int end_index) REQUIRES(lock_);
   void DoMergeInvalMessagesIntoQueueUnlocked(
+      uint32_t db_oid,
       const master::DBCatalogInvalMessagesDataPB& db_catalog_inval_messages_data,
       int start_index,
       int end_index,