From 1a86c130bfa3431ca754f7b4cabf8a780547f60e Mon Sep 17 00:00:00 2001 From: Abit Date: Sun, 3 Jan 2021 17:50:35 +0100 Subject: [PATCH 1/2] Deal with a race condition in logging tests --- tests/logging_tests.cpp | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/tests/logging_tests.cpp b/tests/logging_tests.cpp index ef66501af..d05155b1d 100644 --- a/tests/logging_tests.cpp +++ b/tests/logging_tests.cpp @@ -40,6 +40,7 @@ BOOST_AUTO_TEST_CASE(log_reboot) { fc::log_context ctx(fc::log_level::all, "my_file.cpp", i, "my_method()"); fc::log_message my_log_message( ctx, "${message}", {"message","This is a test"} ); + fc::time_point old_now = fc::time_point::now(); fa->log(my_log_message); fc::time_point now = fc::time_point::now(); @@ -51,7 +52,7 @@ BOOST_AUTO_TEST_CASE(log_reboot) fc::path log_filename = link_filename.parent_path() / (link_filename.filename().string() + "." + timestamp_string); if (prev_log_filename != log_filename) { - if (i > conf.rotation_interval.to_seconds()) { + if (i > conf.rotation_interval.to_seconds() && old_now.sec_since_epoch() / interval_seconds == file_number ) { std::string rez; fc::read_file_contents(prev_log_filename, rez); std::size_t found = rez.find("my_file.cpp:" + std::to_string(i - 1)); @@ -69,4 +70,4 @@ BOOST_AUTO_TEST_CASE(log_reboot) BOOST_TEST_MESSAGE("Loop complete"); } -BOOST_AUTO_TEST_SUITE_END() \ No newline at end of file +BOOST_AUTO_TEST_SUITE_END() From 9fb25cb2e230dee1bddb5b547025533a04e98d19 Mon Sep 17 00:00:00 2001 From: Abit Date: Sun, 3 Jan 2021 18:03:43 +0100 Subject: [PATCH 2/2] Fail the test in extreme cases --- tests/logging_tests.cpp | 13 ++++++++++--- 1 file changed, 10 insertions(+), 3 deletions(-) diff --git a/tests/logging_tests.cpp b/tests/logging_tests.cpp index d05155b1d..217f75a94 100644 --- a/tests/logging_tests.cpp +++ b/tests/logging_tests.cpp @@ -36,23 +36,27 @@ BOOST_AUTO_TEST_CASE(log_reboot) fc::path prev_log_filename = ""; BOOST_TEST_MESSAGE("Starting Loop"); + int file_changed_count = 0; for(int i = 0; i < conf.rotation_limit.to_seconds(); i++) { fc::log_context ctx(fc::log_level::all, "my_file.cpp", i, "my_method()"); fc::log_message my_log_message( ctx, "${message}", {"message","This is a test"} ); - fc::time_point old_now = fc::time_point::now(); + fc::time_point now = fc::time_point::now(); fa->log(my_log_message); - fc::time_point now = fc::time_point::now(); + fc::time_point new_now = fc::time_point::now(); int64_t interval_seconds = conf.rotation_interval.to_seconds(); int64_t file_number = now.sec_since_epoch() / interval_seconds; + bool file_changed = ( new_now.sec_since_epoch() / interval_seconds != file_number ); + if( file_changed ) + ++file_changed_count; fc::time_point_sec start_time = fc::time_point_sec( (uint32_t)(file_number * interval_seconds) ); std::string timestamp_string = start_time.to_non_delimited_iso_string(); fc::path link_filename = conf.filename; fc::path log_filename = link_filename.parent_path() / (link_filename.filename().string() + "." + timestamp_string); if (prev_log_filename != log_filename) { - if (i > conf.rotation_interval.to_seconds() && old_now.sec_since_epoch() / interval_seconds == file_number ) { + if (i > conf.rotation_interval.to_seconds() && !file_changed ) { std::string rez; fc::read_file_contents(prev_log_filename, rez); std::size_t found = rez.find("my_file.cpp:" + std::to_string(i - 1)); @@ -67,6 +71,9 @@ BOOST_AUTO_TEST_CASE(log_reboot) fc::usleep(fc::seconds(1)); } + if( file_changed_count >= 3 ) { + BOOST_FAIL( "It is not expected that file name changes too frequently" ); + } BOOST_TEST_MESSAGE("Loop complete"); }