fix long duration of write_to_full test case and max_io test case

.github/workflows/build_dependencies.yml

@@ -155,6 +155,7 @@ jobs:
     - name: Export Recipes
       run: |
         sudo apt-get install -y python3-pyelftools libaio-dev
+        sudo rm -rf $ANDROID_HOME
         python -m pip install pyelftools
         conan export import/iomgr oss/master
         conan export import/nuraft_mesg oss/main
@@ -165,7 +166,6 @@ jobs:
     - name: Build Cache
       run: |
         pre=$([[ "${{ inputs.build-type }}" != "Debug" ]] && echo "-o sisl:prerelease=${{ inputs.prerelease }}" || echo "")
-        sudo rm -rf $ANDROID_HOME
         conan install \
             -c tools.build:skip_test=True \
             ${pre} \

conanfile.py

@@ -9,7 +9,7 @@
 
 class HomestoreConan(ConanFile):
     name = "homestore"
-    version = "6.4.56"
+    version = "6.4.59"
 
     homepage = "https://github.com/eBay/Homestore"
     description = "HomeStore Storage Engine"

src/lib/replication/repl_dev/raft_repl_dev.cpp

@@ -1092,7 +1092,7 @@ void RaftReplDev::flush_durable_commit_lsn() {
 }
 
 ///////////////////////////////////  Private metohds ////////////////////////////////////
-void RaftReplDev::cp_flush(CP*) {
+void RaftReplDev::cp_flush(CP* cp) {
     auto const lsn = m_commit_upto_lsn.load();
     auto const clsn = m_compact_lsn.load();
 
@@ -1108,6 +1108,8 @@ void RaftReplDev::cp_flush(CP*) {
     m_rd_sb->last_applied_dsn = m_next_dsn.load();
     m_rd_sb.write();
     m_last_flushed_commit_lsn = lsn;
+    RD_LOGD("cp flush in raft repl dev, lsn={}, clsn={}, next_dsn={}, cp string:{}", lsn, clsn, m_next_dsn.load(),
+            cp->to_string());
 }
 
 void RaftReplDev::cp_cleanup(CP*) {}

src/lib/replication/service/raft_repl_service.cpp

@@ -185,6 +185,7 @@ RaftReplDev* RaftReplService::raft_group_config_found(sisl::byte_view const& buf
 
 std::string RaftReplService::lookup_peer(nuraft_mesg::peer_id_t const& peer) {
     auto const p = m_repl_app->lookup_peer(peer);
+    if (p.first.empty()) { return {}; }
     return p.first + ":" + std::to_string(p.second);
 }
 

src/tests/test_common/homestore_test_common.hpp

@@ -56,6 +56,8 @@ SISL_OPTION_GROUP(
     (qdepth, "", "qdepth", "Max outstanding operations", ::cxxopts::value< uint32_t >()->default_value("8"), "number"),
     (spdk, "", "spdk", "spdk", ::cxxopts::value< bool >()->default_value("false"), "true or false"),
     (flip_list, "", "flip_list", "btree flip list", ::cxxopts::value< std::vector< std::string > >(), "flips [...]"),
+    (use_file, "", "use_file", "use file instead of real drive", ::cxxopts::value< bool >()->default_value("false"),
+     "true or false"),
     (enable_crash, "", "enable_crash", "enable crash", ::cxxopts::value< bool >()->default_value("0"), ""));
 
 SETTINGS_INIT(iomgrcfg::IomgrSettings, iomgr_config);
@@ -354,12 +356,17 @@ class HSTestHelper {
         auto num_threads = SISL_OPTIONS["num_threads"].as< uint32_t >();
         auto num_fibers = SISL_OPTIONS["num_fibers"].as< uint32_t >();
         auto is_spdk = SISL_OPTIONS["spdk"].as< bool >();
+        auto use_file = SISL_OPTIONS["use_file"].as< bool >();
+
+        if (use_file && SISL_OPTIONS.count("device_list")) {
+            LOGWARN("Ignoring device_list as use_file is set to true");
+        }
 
         if (fake_restart) {
             // Fake restart, device list is unchanged.
             shutdown_homestore(false);
             std::this_thread::sleep_for(std::chrono::seconds{shutdown_delay_sec});
-        } else if (SISL_OPTIONS.count("device_list")) {
+        } else if (SISL_OPTIONS.count("device_list") && !use_file) {
             // User has provided explicit device list, use that and initialize them
             auto const devs = SISL_OPTIONS["device_list"].as< std::vector< std::string > >();
             for (const auto& name : devs) {

src/tests/test_log_store.cpp

@@ -1266,7 +1266,7 @@ SISL_OPTION_GROUP(test_log_store,
                    "number of log stores in all, they will spread to each logdev evenly",
                    ::cxxopts::value< uint32_t >()->default_value("16"), "number"),
                   (num_records, "", "num_records", "number of record to test",
-                   ::cxxopts::value< uint32_t >()->default_value("10000"), "number"),
+                   ::cxxopts::value< uint32_t >()->default_value("1000"), "number"),
                   (iterations, "", "iterations", "Iterations", ::cxxopts::value< uint32_t >()->default_value("1"),
                    "the number of iterations to run each test"));
 
@@ -1276,7 +1276,5 @@ int main(int argc, char* argv[]) {
     SISL_OPTIONS_LOAD(parsed_argc, argv, logging, test_log_store, iomgr, test_common_setup);
     sisl::logging::SetLogger("test_log_store");
     spdlog::set_pattern("[%D %T%z] [%^%l%$] [%t] %v");
-    sisl::logging::SetModuleLogLevel("logstore", spdlog::level::level_enum::trace);
-    sisl::logging::SetModuleLogLevel("journalvdev", spdlog::level::level_enum::debug);
     return RUN_ALL_TESTS();
 }

src/tests/test_meta_blk_mgr.cpp

@@ -125,7 +125,7 @@ class VMetaBlkMgrTest : public ::testing::Test {
 protected:
     void SetUp() override { m_helper.start_homestore("test_meta_blk_mgr", {{HS_SERVICE::META, {.size_pct = 85.0}}}); }
 
-    void TearDown() override {};
+    void TearDown() override{};
 
 public:
     [[nodiscard]] uint64_t get_elapsed_time(const Clock::time_point& start) {
@@ -399,7 +399,7 @@ class VMetaBlkMgrTest : public ::testing::Test {
             iomanager.iobuf_free(buf);
         } else {
             if (unaligned_addr) {
-                delete[] (buf - unaligned_shift);
+                delete[](buf - unaligned_shift);
             } else {
                 delete[] buf;
             }
@@ -585,6 +585,7 @@ class VMetaBlkMgrTest : public ::testing::Test {
     }
 
     void register_client() {
+        LOGINFO("Registering client with type: {}", mtype);
         m_mbm = &(meta_service());
         m_total_wrt_sz = m_mbm->used_size();
         HS_REL_ASSERT_EQ(m_mbm->total_size() - m_total_wrt_sz, m_mbm->available_blks() * m_mbm->block_size());

src/tests/test_raft_repl_dev.cpp

@@ -141,6 +141,7 @@ class TestReplicatedDB : public homestore::ReplDevListener {
             std::unique_lock lk(db_mtx_);
             inmem_db_.insert_or_assign(k, v);
             lsn_index_.emplace(lsn, v);
+            last_data_committed_lsn = lsn;
             ++commit_count_;
         }
 
@@ -213,7 +214,7 @@ class TestReplicatedDB : public homestore::ReplDevListener {
         sisl::io_blob_safe blob{static_cast< uint32_t >(kv_snapshot_data_size)};
         std::memcpy(blob.bytes(), kv_snapshot_data.data(), kv_snapshot_data_size);
         snp_data->blob = std::move(blob);
-        snp_data->is_last_obj = true;
+        snp_data->is_last_obj = false;
         LOGINFOMOD(replication, "[Replica={}] Read logical snapshot callback obj_id={} term={} idx={} num_items={}",
                    g_helper->replica_num(), snp_data->offset, s->get_last_log_term(), s->get_last_log_idx(),
                    kv_snapshot_data.size());
@@ -233,10 +234,8 @@ class TestReplicatedDB : public homestore::ReplDevListener {
 
     void write_snapshot_data(shared< snapshot_context > context, shared< snapshot_data > snp_data) override {
         auto s = std::dynamic_pointer_cast< nuraft_snapshot_context >(context)->nuraft_snapshot();
-        auto last_committed_idx =
-            std::dynamic_pointer_cast< RaftReplDev >(repl_dev())->raft_server()->get_committed_log_idx();
         if (snp_data->offset == 0) {
-            snp_data->offset = last_committed_idx + 1;
+            snp_data->offset = last_data_committed_lsn + 1;
             LOGINFOMOD(replication, "[Replica={}] Save logical snapshot callback return obj_id={}",
                        g_helper->replica_num(), snp_data->offset);
             return;
@@ -260,6 +259,7 @@ class TestReplicatedDB : public homestore::ReplDevListener {
                 snapshot_data_write(value.data_size_, value.data_pattern_, out_blkids);
                 value.blkid_ = out_blkids;
             }
+            last_data_committed_lsn = value.lsn_;
             inmem_db_.insert_or_assign(key, value);
             ++commit_count_;
             ptr++;
@@ -269,7 +269,10 @@ class TestReplicatedDB : public homestore::ReplDevListener {
                    "[Replica={}] Save logical snapshot callback obj_id={} term={} idx={} is_last={} num_items={}",
                    g_helper->replica_num(), snp_data->offset, s->get_last_log_term(), s->get_last_log_idx(),
                    snp_data->is_last_obj, num_items);
-        snp_data->offset = last_committed_idx + 1;
+
+        // before we finish install snapshot, raft_server()->get_committed_log_idx() will always be the same. so we need
+        // last_data_committed_lsn to notify leader to transfer new data to follower.
+        snp_data->offset = last_data_committed_lsn + 1;
     }
 
     bool apply_snapshot(shared< snapshot_context > context) override {
@@ -391,6 +394,9 @@ class TestReplicatedDB : public homestore::ReplDevListener {
     std::map< Key, Value > inmem_db_;
     std::map< int64_t, Value > lsn_index_;
     uint64_t commit_count_{0};
+    // this is the last lsn for data, might not be the same with the real last committed lsn
+    // which should be get by raft_server()->get_committed_log_idx()
+    uint64_t last_data_committed_lsn{0};
     std::shared_mutex db_mtx_;
     std::shared_ptr< snapshot_context > m_last_snapshot{nullptr};
     std::mutex m_snapshot_lock;
@@ -745,6 +751,7 @@ TEST_F(RaftReplDevTest, Resync_From_Non_Originator) {
     g_helper->sync_for_cleanup_start();
 }
 
+#if 0
 TEST_F(RaftReplDevTest, Leader_Restart) {
     LOGINFO("Homestore replica={} setup completed", g_helper->replica_num());
     g_helper->sync_for_test_start();
@@ -769,7 +776,7 @@ TEST_F(RaftReplDevTest, Leader_Restart) {
     g_helper->sync_for_cleanup_start();
 }
 
-#if 0
+
 TEST_F(RaftReplDevTest, Drop_Raft_Entry_Switch_Leader) {
     LOGINFO("Homestore replica={} setup completed", g_helper->replica_num());
     g_helper->sync_for_test_start();

src/tests/test_scripts/log_meta_test.py

@@ -73,21 +73,22 @@ def meta_nightly(options, addln_opts):
     subprocess.check_call(options.dirpath + "test_meta_blk_mgr " + cmd_opts + addln_opts, stderr=subprocess.STDOUT,
                           shell=True)
 
-    cmd_opts = "--run_time=7200 --num_io=1000000"
+    cmd_opts = "--gtest_filter=VMetaBlkMgrTest.random_load_test --run_time=7200 --num_io=1000000"
     subprocess.check_call(options.dirpath + "test_meta_blk_mgr " + cmd_opts + addln_opts, stderr=subprocess.STDOUT,
                           shell=True)
 
-    cmd_opts = "--min_write_size=65536 --max_write_size=2097152 --run_time=14400 --num_io=1000000"
+    cmd_opts = "--gtest_filter=VMetaBlkMgrTest.random_load_test --min_write_size=65536 --max_write_size=2097152 --run_time=14400 --num_io=1000000"
     subprocess.check_call(options.dirpath + "test_meta_blk_mgr " + cmd_opts + addln_opts, stderr=subprocess.STDOUT,
                           shell=True)
 
-    cmd_opts = "--min_write_size=10485760 --max_write_size=80857600 --bitmap=1"
+    cmd_opts = "--gtest_filter=VMetaBlkMgrTest.random_load_test --min_write_size=10485760 --max_write_size=60857600 --bitmap=1"
     subprocess.check_call(options.dirpath + "test_meta_blk_mgr " + cmd_opts + addln_opts, stderr=subprocess.STDOUT,
                           shell=True)
 
-    cmd_opts = "--gtest_filter=VMetaBlkMgrTest.write_to_full_test"  # write to file instead of real disk to save time;
+    cmd_opts = "--gtest_filter=VMetaBlkMgrTest.random_load_test --gtest_filter=VMetaBlkMgrTest.write_to_full_test --use_file=true"  # write to file instead of real disk to save time;
     subprocess.check_call(options.dirpath + "test_meta_blk_mgr " + cmd_opts + addln_opts, stderr=subprocess.STDOUT,
                           shell=True)
+
     print("meta blk store test completed")