From: Thomas Markwalder Date: Tue, 23 Jul 2019 19:29:40 +0000 (-0400) Subject: [#174,!414] Cleaned up fractional seconds handling X-Git-Tag: Kea-1.6.1~10^2~113 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=d6af450a29ba9857410b30cd76e9822fd9849515;p=thirdparty%2Fkea.git [#174,!414] Cleaned up fractional seconds handling src/hooks/dhcp/high_availability/communication_state.* CommunicationState::logFormatClockSkew() - generates log without fractional seconds src/hooks/dhcp/high_availability/tests/communication_state_unittest.cc TEST_F(CommunicationStateTest, logFormatClockSkew) - added check of entire log content src/lib/http/date_time.* HttpDateTime::HttpDateTime() now uses second_clock to eliminate fractional seconds src/lib/util/boost_time_utils.* ptimeToText() durationToText() - added fsecs_precision parameter to control fractional seconds emission src/lib/util/tests/boost_time_utils_unittest.cc TEST(BoostTimeUtilsTest, epoch) TEST(BoostTimeUtilsTest, bastilleDay) - revamped to test precision --- diff --git a/src/hooks/dhcp/high_availability/communication_state.cc b/src/hooks/dhcp/high_availability/communication_state.cc index 2a159c4770..6ffd48f827 100644 --- a/src/hooks/dhcp/high_availability/communication_state.cc +++ b/src/hooks/dhcp/high_availability/communication_state.cc @@ -219,7 +219,6 @@ void CommunicationState::setPartnerTime(const std::string& time_text) { partner_time_at_skew_ = HttpDateTime().fromRfc1123(time_text).getPtime(); my_time_at_skew_ = HttpDateTime().getPtime(); - clock_skew_ = partner_time_at_skew_ - my_time_at_skew_; } @@ -234,8 +233,10 @@ CommunicationState::logFormatClockSkew() const { return ("skew not initialized"); } - os << "my time: " << util::ptimeToText(my_time_at_skew_) - << ", partner's time: " << util::ptimeToText(partner_time_at_skew_) + // Note HttpTime resolution is only to seconds, so we use fractional + // precision of zero when logging. + os << "my time: " << util::ptimeToText(my_time_at_skew_, 0) + << ", partner's time: " << util::ptimeToText(partner_time_at_skew_, 0) << ", partner's clock is "; // If negative clock skew, the partner's time is behind our time. diff --git a/src/hooks/dhcp/high_availability/tests/communication_state_unittest.cc b/src/hooks/dhcp/high_availability/tests/communication_state_unittest.cc index 7141b8c07f..6213d87afe 100644 --- a/src/hooks/dhcp/high_availability/tests/communication_state_unittest.cc +++ b/src/hooks/dhcp/high_availability/tests/communication_state_unittest.cc @@ -26,6 +26,9 @@ using namespace isc::dhcp; using namespace isc::ha; using namespace isc::ha::test; using namespace isc::http; +using namespace boost::posix_time; +using namespace boost::gregorian; + namespace { @@ -378,19 +381,33 @@ TEST_F(CommunicationStateTest, logFormatClockSkew) { boost::posix_time::ptime now = HttpDateTime().getPtime(); // Partner time is ahead by 15s. - boost::posix_time::time_duration offset(0,0,15,0); + boost::posix_time::time_duration offset(0,0,15); state_.setPartnerTime(HttpDateTime(now + offset).rfc1123Format()); ASSERT_NO_THROW(log = state_.logFormatClockSkew()); + // We don't check the exact string for obvious reasons. - EXPECT_TRUE(log.find("s ahead") != std::string::npos) << + EXPECT_TRUE(log.find("15s ahead") != std::string::npos) << " log content wrong: " << log; + // Partner time is behind by 15s. state_.setPartnerTime(HttpDateTime(now - offset).rfc1123Format()); ASSERT_NO_THROW(log = state_.logFormatClockSkew()); // We don't check the exact string for obvious reasons. - EXPECT_TRUE(log.find("s behind") != std::string::npos) << + EXPECT_TRUE(log.find("15s behind") != std::string::npos) << " log content wrong: " << log; + + offset = hours(18) + minutes(37) + seconds(15); + ptime mytime(date(2019, Jul, 23), offset); + + state_.my_time_at_skew_ = mytime; + state_.partner_time_at_skew_ = mytime + seconds(25); + state_.clock_skew_ = seconds(25); + ASSERT_NO_THROW(log = state_.logFormatClockSkew()); + std::string expected("my time: 2019-07-23 18:37:15, " + "partner's time: 2019-07-23 18:37:40, " + "partner's clock is 25s ahead"); + EXPECT_EQ(expected, log); } } diff --git a/src/hooks/dhcp/high_availability/tests/ha_test.h b/src/hooks/dhcp/high_availability/tests/ha_test.h index a668e9e8aa..5597098a4c 100644 --- a/src/hooks/dhcp/high_availability/tests/ha_test.h +++ b/src/hooks/dhcp/high_availability/tests/ha_test.h @@ -65,6 +65,8 @@ public: using StateType::timer_; using StateType::clock_skew_; using StateType::last_clock_skew_warn_; + using StateType::my_time_at_skew_; + using StateType::partner_time_at_skew_; }; /// @brief Type of the NakedCommunicationState for DHCPv4. diff --git a/src/lib/http/date_time.cc b/src/lib/http/date_time.cc index ba2c6c516b..e118bf3fec 100644 --- a/src/lib/http/date_time.cc +++ b/src/lib/http/date_time.cc @@ -19,7 +19,7 @@ namespace isc { namespace http { HttpDateTime::HttpDateTime() - : time_(boost::posix_time::microsec_clock::universal_time()) { + : time_(boost::posix_time::second_clock::universal_time()) { } HttpDateTime::HttpDateTime(const boost::posix_time::ptime& t) diff --git a/src/lib/http/date_time.h b/src/lib/http/date_time.h index 16875d476c..309f5a1903 100644 --- a/src/lib/http/date_time.h +++ b/src/lib/http/date_time.h @@ -43,7 +43,8 @@ public: /// @brief Default constructor. /// - /// Sets current universal time as time value. + /// Sets current universal time as time value. + /// Time resolution is to seconds (i.e no fractional seconds). HttpDateTime(); /// @brief Construct from @c boost::posix_time::ptime object. diff --git a/src/lib/util/boost_time_utils.cc b/src/lib/util/boost_time_utils.cc index 8c5ab0848e..e35f3a1f75 100644 --- a/src/lib/util/boost_time_utils.cc +++ b/src/lib/util/boost_time_utils.cc @@ -11,25 +11,38 @@ #include std::string -isc::util::ptimeToText(boost::posix_time::ptime t) { +isc::util::ptimeToText(boost::posix_time::ptime t, size_t fsecs_precision) { boost::gregorian::date d = t.date(); std::stringstream s; s << d.year() << "-" << std::setw(2) << std::setfill('0') << d.month().as_number() << "-" << std::setw(2) << std::setfill('0') << d.day() - << " " << durationToText(t.time_of_day()); + << " " << durationToText(t.time_of_day(), fsecs_precision); return (s.str()); } std::string -isc::util::durationToText(boost::posix_time::time_duration dur) { +isc::util::durationToText(boost::posix_time::time_duration dur, size_t fsecs_precision) { std::stringstream s; s << std::setw(2) << std::setfill('0') << dur.hours() << ":" << std::setw(2) << std::setfill('0') << dur.minutes() - << ":" << std::setw(2) << std::setfill('0') << dur.seconds() - << "." << std::setw(boost::posix_time::time_duration::num_fractional_digits()) - << std::setfill('0') - << dur.fractional_seconds(); + << ":" << std::setw(2) << std::setfill('0') << dur.seconds(); + + if (fsecs_precision) { + size_t fsecs = dur.fractional_seconds(); + size_t width = DEFAULT_FRAC_SECS; + if (fsecs_precision < width) { + for (size_t diff = width - fsecs_precision; diff; --diff) { + fsecs /= 10; + } + + width = fsecs_precision; + } + + s << "." << std::setw(width) + << std::setfill('0') + << fsecs; + } return (s.str()); } diff --git a/src/lib/util/boost_time_utils.h b/src/lib/util/boost_time_utils.h index befe02ccaa..74ed36d392 100644 --- a/src/lib/util/boost_time_utils.h +++ b/src/lib/util/boost_time_utils.h @@ -13,6 +13,8 @@ namespace isc { namespace util { +const size_t DEFAULT_FRAC_SECS=boost::posix_time::time_duration::num_fractional_digits(); + /// @brief Converts ptime structure to text /// /// This is Kea implementation for converting ptime to strings. @@ -24,17 +26,27 @@ namespace util { /// be needed on OS X. Since the functionality needed is minor, we decided to /// reimplement it on our own, rather than introduce extra dependencies. /// This explanation also applies to @ref durationToText. +/// @param t ptime value to convert to text +/// @param fsecs_precision number of digits of precision for fractional seconds. +/// Default is given by boost::posix_time::time_duration::num_fractional_digits(). +/// Zero omits the value. /// /// @return a string representing time -std::string ptimeToText(boost::posix_time::ptime t); +std::string ptimeToText(boost::posix_time::ptime t, + size_t fsecs_precision = DEFAULT_FRAC_SECS); /// @brief Converts StatsDuration to text /// /// This is Kea equivalent of boost::posix_time::to_simple_string(time_duration). /// See @ref ptimeToText for explanation why we chose our own implementation. +/// @param dur duration value to convert to text +/// @param fsecs_precision number of digits of precision for fractional seconds. +/// Default is given by boost::posix_time::time_duration::num_fractional_digits(). +/// Zero omits the value. /// /// @return a string representing time -std::string durationToText(boost::posix_time::time_duration dur); +std::string durationToText(boost::posix_time::time_duration dur, + size_t fsecs_precision = DEFAULT_FRAC_SECS); }; // end of isc::util namespace }; // end of isc namespace diff --git a/src/lib/util/tests/boost_time_utils_unittest.cc b/src/lib/util/tests/boost_time_utils_unittest.cc index 8838b484b2..db80d7f912 100644 --- a/src/lib/util/tests/boost_time_utils_unittest.cc +++ b/src/lib/util/tests/boost_time_utils_unittest.cc @@ -24,8 +24,32 @@ using namespace boost::gregorian; TEST(BoostTimeUtilsTest, epoch) { time_t tepoch = 0; ptime pepoch = from_time_t(tepoch); - string sepoch = ptimeToText(pepoch); - EXPECT_EQ("1970-01-01 00:00:00.000", sepoch.substr(0, 23)); + + std::string expected("1970-01-01 00:00:00"); + std::string sepoch; + for (int precision = 0; precision <= DEFAULT_FRAC_SECS; ++precision) { + if (precision == 1) { + expected.push_back('.'); + } + + if (precision >= 1) { + expected.push_back('0'); + } + + sepoch = ptimeToText(pepoch, precision); + EXPECT_EQ(expected, sepoch) << " test precision:" << precision; + } + + // Expected string should have same precision as default, so + // test the default. + sepoch = ptimeToText(pepoch); + EXPECT_EQ(expected, sepoch); + + // Now test a requested precision beyond default. We should + // get the default precision. + sepoch = ptimeToText(pepoch, DEFAULT_FRAC_SECS + 1); + EXPECT_EQ(expected, sepoch); + } // The 2015 Bastille day @@ -33,6 +57,28 @@ TEST(BoostTimeUtilsTest, bastilleDay) { time_duration tdbast = hours(12) + minutes(13) + seconds(14) + milliseconds(500); ptime pbast(date(2015, Jul, 14), tdbast); - string sbast = ptimeToText(pbast); - EXPECT_EQ("2015-07-14 12:13:14.500", sbast.substr(0, 23)); + + std::string expected("2015-07-14 12:13:14"); + std::string sbast; + for (int precision = 0; precision <= DEFAULT_FRAC_SECS; ++precision) { + if (precision == 1) { + expected.push_back('.'); + expected.push_back('5'); + } else if (precision > 1) { + expected.push_back('0'); + } + + sbast = ptimeToText(pbast, precision); + EXPECT_EQ(expected, sbast) << " test precision:" << precision; + } + + // Expected string should have same precision as default, so + // test the default. + sbast = ptimeToText(pbast); + EXPECT_EQ(expected, sbast); + + // Now test a requested precision beyond default. We should + // get the default precision. + sbast = ptimeToText(pbast, DEFAULT_FRAC_SECS + 1); + EXPECT_EQ(expected, sbast); }