From 17e0c06ee4211936bdd148d472fd389204ca3ded Mon Sep 17 00:00:00 2001
From: Shinichi Umegane <sumegane@nifty.com>
Date: Tue, 26 Nov 2024 19:10:14 +0900
Subject: [PATCH] Integrate trace logs for issue investigation

---
 src/limestone/datastore.cpp             | 7 +++++++
 src/limestone/log_channel.cpp           | 4 ++++
 test/limestone/compaction/test_1034.cpp | 2 +-
 3 files changed, 12 insertions(+), 1 deletion(-)

diff --git a/src/limestone/datastore.cpp b/src/limestone/datastore.cpp
index ea68b08..d308deb 100644
--- a/src/limestone/datastore.cpp
+++ b/src/limestone/datastore.cpp
@@ -156,6 +156,7 @@ void datastore::switch_epoch(epoch_id_type new_epoch_id) {
 }
 
 void datastore::update_min_epoch_id(bool from_switch_epoch) {  // NOLINT(readability-function-cognitive-complexity)
+    VLOG_LP(log_info) << "start update_min_epoch_id() with from_switch_epoch=" << from_switch_epoch;
     auto upper_limit = epoch_id_switched_.load() - 1;
     epoch_id_type max_finished_epoch = 0;
 
@@ -170,6 +171,8 @@ void datastore::update_min_epoch_id(bool from_switch_epoch) {  // NOLINT(readabi
         }
     }
 
+    VLOG_LP(log_info) << "epoch_id_switched_ = " << epoch_id_switched_.load() << ", upper_limit = " << upper_limit << ", max_finished_epoch = " << max_finished_epoch;
+
     // update recorded_epoch_
     auto to_be_epoch = upper_limit;
     if (from_switch_epoch && (to_be_epoch > static_cast<std::uint64_t>(max_finished_epoch))) {
@@ -181,6 +184,7 @@ void datastore::update_min_epoch_id(bool from_switch_epoch) {  // NOLINT(readabi
             break;
         }
         if (epoch_id_recorded_.compare_exchange_strong(old_epoch_id, to_be_epoch)) {
+            VLOG_LP(log_info) << "start update epooch file to " << to_be_epoch;
             std::lock_guard<std::mutex> lock(mtx_epoch_file_);
 
             FILE* strm = fopen(epoch_file_path_.c_str(), "a");  // NOLINT(*-owning-memory)
@@ -197,6 +201,7 @@ void datastore::update_min_epoch_id(bool from_switch_epoch) {  // NOLINT(readabi
             if (fclose(strm) != 0) {  // NOLINT(*-owning-memory)
                 LOG_AND_THROW_IO_EXCEPTION("fclose failed", errno);
             }
+            VLOG_LP(log_info) << "end update epooch file to " << to_be_epoch;
             break;
         }
     }
@@ -210,7 +215,9 @@ void datastore::update_min_epoch_id(bool from_switch_epoch) {  // NOLINT(readabi
         }
         if (epoch_id_informed_.compare_exchange_strong(old_epoch_id, to_be_epoch)) {
             if (persistent_callback_) {
+                VLOG_LP(log_info) << "start calling persistent callback to " << to_be_epoch;
                 persistent_callback_(to_be_epoch);
+                VLOG_LP(log_info) << "end calling persistent callback to " << to_be_epoch;
             }
             break;
         }
diff --git a/src/limestone/log_channel.cpp b/src/limestone/log_channel.cpp
index 525982b..d21a04f 100644
--- a/src/limestone/log_channel.cpp
+++ b/src/limestone/log_channel.cpp
@@ -45,6 +45,7 @@ void log_channel::begin_session() {
             current_epoch_id_.store(envelope_.epoch_id_switched_.load());
             std::atomic_thread_fence(std::memory_order_acq_rel);
         } while (current_epoch_id_.load() != envelope_.epoch_id_switched_.load());
+        VLOG_LP(log_info) << "start begin_session() with current_epoch_id_=" << current_epoch_id_.load();
         latest_ession_epoch_id_.store(static_cast<epoch_id_type>(current_epoch_id_.load()));
 
         auto log_file = file_path();
@@ -62,6 +63,7 @@ void log_channel::begin_session() {
             std::lock_guard<std::mutex> lock(session_mutex_);
             waiting_epoch_ids_.insert(latest_ession_epoch_id_);
         }
+        VLOG_LP(log_info) << "end begin_session() with current_epoch_id_=" << current_epoch_id_.load();
     } catch (...) {
         HANDLE_EXCEPTION_AND_ABORT();
     }
@@ -69,6 +71,7 @@ void log_channel::begin_session() {
 
 void log_channel::end_session() {
     try {
+        VLOG_LP(log_info) << "start end_session() with current_epoch_id_=" << current_epoch_id_.load();
         if (fflush(strm_) != 0) {
             LOG_AND_THROW_IO_EXCEPTION("fflush failed", errno);
         }
@@ -90,6 +93,7 @@ void log_channel::end_session() {
             // Notify waiting threads
             session_cv_.notify_all();
         }
+        VLOG_LP(log_info) << "end end_session() with current_epoch_id_=" << current_epoch_id_.load();
     } catch (...) {
         HANDLE_EXCEPTION_AND_ABORT();
     }
diff --git a/test/limestone/compaction/test_1034.cpp b/test/limestone/compaction/test_1034.cpp
index 5815e41..c54c950 100644
--- a/test/limestone/compaction/test_1034.cpp
+++ b/test/limestone/compaction/test_1034.cpp
@@ -229,7 +229,7 @@ class test_1034 : public ::testing::Test {
     }
 };
 
-TEST_F(test_1034, display_pwal_files) {
+TEST_F(test_1034, DISABLED_parse_pwals) {
     boost::filesystem::path location = boost::filesystem::path("../../test_data");
 
     // ディレクトリ内のファイルを列挙